Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for
- Cisco Community
- :
- About Joli Martinez
Stats
Member since
08-27-2011
159
Posts
0
Helpful
2
Solutions
03-27-2020
08:22 AM
I have an analog line coming in from the provider and I need to send it to the IPPBX. I have gone back to basics and I can't seem to get the analog line to pass the call to the SIP Stack. I have debugged ccsip and vpm signal. I am seeing the call come in the debug, but only on the fx0 port the call never reaches the sip stack. Call just rings and it sound like it is picked up and get dead air. The call flow is as follows PSTN Call -> FXO 0/0 -> Cisco 2911 -> session target IPPBX on extension 1000 voice-port 0/0 connection plar 1000 caller-id enable ! ! dial-peer voice 100 pots incoming called-number .T direct-inward-dial port 0/0 ! ! dial-peer voice 1000 voip destination-pattern .T session target ipv4:10.41.100.2
... View more
Labels:
03-26-2020
02:13 PM
The carrier is delivering an analog port to an IAD. The IAD is supposed to send it to an IPPBX. When I call the number it appears the call is picked up and all I get is dead air. The call never goes to the PBX. I have changed the dial-peers to .T to make sure they match. I will change them to a more precise match once I figure out what is going on. voice-port 0/0 connection plar 1000 caller-id enable ! dial-peer voice 100 pots description Incoming Called number X incoming called-number .T direct-inward-dial port 0/0 ! dial-peer voice 1000 voip destination-pattern .T session target ipv4:10.41.100.2 ############################################################ *Mar 15 02:14:42.568: htsp_process_event: [0/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing *Mar 15 02:14:42.568: htsp_timer - 125 msec *Mar 15 02:14:42.696: htsp_process_event: [0/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer *Mar 15 02:14:42.696: htsp_timer - 10000 msec *Mar 15 02:14:42.696: htsp_timer3 - 5600 msec *Mar 15 02:14:42.696: [0/0] htsp_start_caller_id_rx:BELLCORE *Mar 15 02:14:42.696: htsp_start_caller_id_rx create dsp_stream_manager *Mar 15 02:14:42.696: [0/0] htsp_dsm_create_success returns 1 *Mar 15 02:14:44.792: htsp_process_event: [0/0, FXOLS_RINGING, E_DSP_SIG_0100] *Mar 15 02:14:44.792: fxols_ringing_not *Mar 15 02:14:44.792: htsp_timer_stop *Mar 15 02:14:44.792: htsp_timer - 10000 msec *Mar 15 02:14:45.888: [0/0] htsp_dsm_feature_notify_cb returns 2 id=DSM_FEATURE_SM_CALLERID_RX *Mar 15 02:14:45.888: htsp_process_event: [0/0, FXOLS_RINGING, E_HTSP_CALLERID_RX_DONE] *Mar 15 02:14:45.888: htsp_timer_stop *Mar 15 02:14:45.888: htsp_timer_stop3 *Mar 15 02:14:45.888: [0/0] htsp_stop_caller_id_rx. message length 40htsp_setup_ind *Mar 15 02:14:45.888: [0/0] get_fxo_caller_id:Caller ID received. Message type=128 length=40 checksum=D7 *Mar 15 02:14:45.888: [0/0] Caller ID String 80 25 02 0B 31 36 37 38 33 39 31 36 36 37 36 01 08 30 33 32 36 31 36 30 36 07 0C 2B 31 36 37 38 33 39 31 36 36 37 36 D7 *Mar 15 02:14:45.892: [0/0] get_fxo_caller_id calling num=1333444555 calling name=+13334445555calling time=03/26 16:06 *Mar 15 02:14:45.892: fxols_callerid_done: call being answered *Mar 15 02:14:45.900: htsp_process_event: [0/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK] *Mar 15 02:14:45.900: fxols_wait_setup_ack: *Mar 15 02:14:45.900: [0/0] set signal state = 0xC timestamp = 0fxols_check_auto_call *Mar 15 02:14:45.912: htsp_process_event: [0/0, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_proc *Mar 15 02:14:45.912: htsp_timer - 120000 msec *Mar 15 02:14:45.916: [0/0] htsp_dsm_close_done
... View more
Labels:
03-21-2020
11:07 AM
I have an old 2400 series IAD. I am configuring this for SIP traffic. Is there anything special I need to do to enable SIP on it. I have configured the dial-peer below and it is not sending the traffic to session target. I see the call comes in and it matches this dial-peer correctly, but from there the call dies and never goes out. What am I missing? dial-peer voice 103 voip description 10 Digit Dialing translation-profile outgoing E164 destination-pattern [2-9]......... session protocol sipv2 session target ipv4:10.21.10.10 session transport udp dtmf-relay rtp-nte codec g711ulaw fax-relay ecm disable fax-relay sg3-to-g3 ip qos dscp cs5 media ip qos dscp cs4 signaling no vad ########################################################### INVITE sip:3334445555@10.41.100.5 SIP/2.0 Via: SIP/2.0/UDP 10.41.100.2:5080;rport;branch=z9hG4bKetaj2eS80yNQa Max-Forwards: 69 From: "LCS" <sip:FreeSWITCH@10.41.100.5>;tag=eKvvvN70gKveQ To: <sip:3334445555@10.41.100.5> Call-ID: 231b0a87-e56b-1238-0aa6-005056873da3 CSeq: 17807162 INVITE Contact: <sip:gw+17530ce2-2aba-4f3e-8a16-dc3295c03661@10.41.100.2:5080;transport=udp;gw=17530ce2-2aba-4f3e-8a16-dc3295c03661> User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 293 X-FS-Support: update_display,send_info Remote-Party-ID: "LCS" <sip:7778889999@10.41.100.5>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1584696828 1584696829 IN IP4 10.41.100.2 s=FreeSWITCH c=IN IP4 10.41.100.2 t=0 0 m=audio 24384 RTP/AVP 9 0 8 101 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x65BA5380) with key=[31] to table *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.41.100.2,Port 5080, Transport 1, SentBy Port 5080 *Mar 8 21:28:55.148: //-1/53D840FF8066/SIP/State/sipSPIChangeState: 0x65BA5380 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.41.100.2,Port 5080, Transport 1, SentBy Port 5060 *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.41.100.2,Port 5080, Transport 1, SentBy Port 5080 *Mar 8 21:28:55.152: //-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_lock: Increment msg (0x657AF4E8) counter, current msg->refCount = 2 *Mar 8 21:28:55.152: //-1/xxxxxxxxxxxx/SIP/Error/httpish_msg_free: Freeing NULL pointer! *Mar 8 21:28:55.152: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAssignCcbLastRequest: Current ccb(0x65BA5380)->last_request = 0x657AF4E8, refCount = 2 *Mar 8 21:28:55.152: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x640D45FC) found for sip_user: 3334445555 *Mar 8 21:28:55.152: //-1/53D840FF8066/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: LCS, current remote number: 7778889999 *Mar 8 21:28:55.152: //-1/53D840FF8066/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=yes ;privacy=off -> Setting Octet3A 0x81, extended_privacy 0x00 *Mar 8 21:28:55.152: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container *Mar 8 21:28:55.152: //-1/53D840FF8066/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table. *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x65BA5380 key=231b0a87-e56b-1238-0aa6-005056873da33334445555 *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 3334445555 *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 7778889999 *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name LCS, number 7778889999, Calling oct3 0x00, oct_3a 0x81, Called number 3334445555 *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Peer tag 103 matched for incoming call *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 711 *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Media/sipSPICopyPeerDataToCCB: Firewall traversal is not enabled *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Media forking disabled *Mar 8 21:28:55.160: //-1/53D840FF8066/SIP/Info/sipSPIContinueNewMsgInvite: Calling name LCS, number 7778889999, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 3334445555, oct3 0x00 *Mar 8 21:28:55.160: //-1/53D840FF8066/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE *Mar 8 21:28:55.160: //-1/53D840FF8066/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0 *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1 SIP: (19) Attribute mid, level 1 instance 1 not found. *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.41.100.5 *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Media/sipSPISelectCodecVersion: g722-64 flavor of G722 codec will be used *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Info/sipSPIDoAudioNegotiation: Codec (g722-64) Negotiation Successful on Static Payload for m-line 1 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20 *Mar 8 21:28:55.164: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g722-64 ptime :20, codecbytes: 160 *Mar 8 21:28:55.164: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g722-64 codecbytes :160, ptime: 20 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g722-64 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved. *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full named event(NE) match in fmtp list of events. *Mar 8 21:28:55.164: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay *Mar 8 21:28:55.164: //19/53D840FF8066/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 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1 payload_type=9, codec_bytes=160, codec=g722-64, dtmf_relay=rtp-nte stream_type=voice+dtmf (1), dest_ip_address=10.41.100.2, dest_port=24384 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) *Mar 8 21:28:55.164: //19/53D840FF8066/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 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.41.100.5 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: callId 19 peer 0 flags 0x201 state STATE_IDLE *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: CallID 19, sdp 0x65EFE538 channels 0x65BA6640 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/copy_channels: callId 19 size 0 ptr 0x657B2670) *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 9 mline 1 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Media/sipSPISelectCodecVersion: g722-64 flavor of G722 codec will be used *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g722-64 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/codec_found: Codec to be matched: 37 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 37 *Mar 8 21:28:55.168: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g722-64 codecbytes :160, ptime: 20 *Mar 8 21:28:55.168: //19/53D840FF8066/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 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo: failed to update call entry *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Adding codec 37 ptype 9 time 20, bytes 160 as channel 0 mline 1 ss 0 10.41.100.2:24384 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 0 mline 1 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/codec_found: Codec to be matched: 5 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=20, media_ndx=1 *Mar 8 21:28:55.168: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :20, codecbytes: 160 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo: failed to update call entry *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Adding codec 5 ptype 0 time 20, bytes 160 as channel 1 mline 1 ss 0 10.41.100.2:24384 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 8 mline 1 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/codec_found: Codec to be matched: 6 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=20, media_ndx=1 *Mar 8 21:28:55.168: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo: failed to update call entry *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Adding codec 6 ptype 8 time 20, bytes 160 as channel 2 mline 1 ss 0 10.41.100.2:24384 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 101 mline 1 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 19, dtmf = 6 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 37 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 6 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: callId 19 flags 0x300 state STATE_IDLE *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: Report initial call media *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC, ccb->pld.flags_ipip 0x201 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/copy_channels: callId 19 size 696 ptr 0x65EE0014) *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: CCSIP: Unable to report channel ind *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/ccsip_update_srtp_caps: 5054: Posting Remote SRTP caps to other callleg. *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: do cc_api_caps_ind() *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : -1 Negotiated Codec : g722-64, bytes :160 Nego. Codec payload : 9 (tx), 9 (rx) Negotiated DTMF relay : rtp-nte Negotiated NTE payload : 101 (tx), 101 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [10.41.100.5]:0 Media Dest Addr/Port : [10.41.100.2]:24384 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPIHandleInviteMedia: Negotiated Codec : g722-64, bytes :160 Preferred Codec : g711ulaw, bytes :160 Preferred DTMF relay 1 : 6 Preferred DTMF relay 2 : 0 Negotiated DTMF relay : 6 Preferred and Negotiated NTE payloads: 101 101 Preferred and Negotiated NSE payloads: 100 0 Preferred and Negotiated Modem Relay: 0 0 Preferred and Negotiated Modem Relay GwXid: 1 0 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: Entry *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 16700 for stream 1 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=16700 *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 16700 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIUpdateSrcSdpVariablePart: SIP update src sdp, negoitated codec 37, payload type 9 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 101 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 231b0a87-e56b-1238-0aa6-005056873da3 *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotiated dtmf = 6, *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIShrlCall: Check peer: 103 for Shared-Line call, callid: 19 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/ccsip_set_bearer_capability: Bearer Capability: Speech (0x00) *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 13 to table *Mar 8 21:28:55.180: //-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_create: created msg=0x65E5A6A0 with refCount = 1 *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Transport/sipSPITransportSendMessage: msg=0x65E5A6A0, addr=10.41.100.2, port=5080, sentBy_port=5080, is_req=0, transport=1, switch=0, callBack=0x00000000 *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 *Mar 8 21:28:55.180: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x65E5A6A0, addr=10.41.100.2, port=5080, connId=0 for UDP *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/State/sipSPIChangeState: 0x65BA5380 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_RECD_INVITE, SUBSTATE_NONE) *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Info/sipSPIProcessContactInfo: Previous Hop 10.41.100.2:5080 *Mar 8 21:28:55.184: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING *Mar 8 21:28:55.188: //19/53D840FF8066/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call. *Mar 8 21:28:55.188: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT *Mar 8 21:28:55.188: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 3 *Mar 8 21:28:55.188: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 7 *Mar 8 21:28:55.188: //19/53D840FF8066/SIP/Info/act_recdinvite_disconnect: Performing disconnect *Mar 8 21:28:55.192: //-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_create: created msg=0x64DC9174 with refCount = 1 *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table. *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x65BA5380 key=231b0a87-e56b-1238-0aa6-005056873da328A88EC8-DDC *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Info/sipSPISendInviteResponse: Associated container=0x65D9D688 to Invite Response 404 *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Transport/sipSPITransportSendMessage: msg=0x64DC9174, addr=10.41.100.2, port=5080, sentBy_port=5080, is_req=0, transport=1, switch=0, callBack=0x61B0A9D4 *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 *Mar 8 21:28:55.192: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x64DC9174, addr=10.41.100.2, port=5080, connId=0 for UDP *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Info/sentErrResDisconnecting: Sent an 3456XX Error Response *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/State/sipSPIChangeState: 0x65BA5380 : State change from (STATE_RECD_INVITE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE) *Mar 8 21:28:55.196: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Sent:
... View more
Labels:
03-20-2020
09:50 AM
I have a call from Freeswitch to an IAD going back to our SBC. The dial-peer is matched but I am having some sort of codec mismatch and not sure how to fix it. I have forced the IAD to use g711 and it still fails. I have added g711ulaw and a law as well as g722 and it still fails. Not sure where to go from here. voice class codec 711 codec preference 1 g711ulaw codec preference 2 g711alaw codec preference 3 g722-64 dial-peer voice 103 voip description 10 Digit Dialing translation-profile outgoing E164 destination-pattern [2-9]......... progress_ind setup enable 3 voice-class codec 711 session protocol sipv2 session target dns:sip.oursbc.com session transport udp dtmf-relay rtp-nte no fax-relay sg3-to-g3 ip qos dscp cs5 media ip qos dscp cs4 signaling no vad ! INVITE sip:3334445555@10.41.100.5 SIP/2.0 Via: SIP/2.0/UDP 10.41.100.2:5080;rport;branch=z9hG4bKetaj2eS80yNQa Max-Forwards: 69 From: "LCS" <sip:FreeSWITCH@10.41.100.5>;tag=eKvvvN70gKveQ To: <sip:3334445555@10.41.100.5> Call-ID: 231b0a87-e56b-1238-0aa6-005056873da3 CSeq: 17807162 INVITE Contact: <sip:gw+17530ce2-2aba-4f3e-8a16-dc3295c03661@10.41.100.2:5080;transport=udp;gw=17530ce2-2aba-4f3e-8a16-dc3295c03661> User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 293 X-FS-Support: update_display,send_info Remote-Party-ID: "LCS" <sip:7778889999@10.41.100.5>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1584696828 1584696829 IN IP4 10.41.100.2 s=FreeSWITCH c=IN IP4 10.41.100.2 t=0 0 m=audio 24384 RTP/AVP 9 0 8 101 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x65BA5380) with key=[31] to table *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.41.100.2,Port 5080, Transport 1, SentBy Port 5080 *Mar 8 21:28:55.148: //-1/53D840FF8066/SIP/State/sipSPIChangeState: 0x65BA5380 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.41.100.2,Port 5080, Transport 1, SentBy Port 5060 *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT *Mar 8 21:28:55.148: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.41.100.2,Port 5080, Transport 1, SentBy Port 5080 *Mar 8 21:28:55.152: //-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_lock: Increment msg (0x657AF4E8) counter, current msg->refCount = 2 *Mar 8 21:28:55.152: //-1/xxxxxxxxxxxx/SIP/Error/httpish_msg_free: Freeing NULL pointer! *Mar 8 21:28:55.152: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAssignCcbLastRequest: Current ccb(0x65BA5380)->last_request = 0x657AF4E8, refCount = 2 *Mar 8 21:28:55.152: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x640D45FC) found for sip_user: 3334445555 *Mar 8 21:28:55.152: //-1/53D840FF8066/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: LCS, current remote number: 7778889999 *Mar 8 21:28:55.152: //-1/53D840FF8066/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=yes ;privacy=off -> Setting Octet3A 0x81, extended_privacy 0x00 *Mar 8 21:28:55.152: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container *Mar 8 21:28:55.152: //-1/53D840FF8066/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table. *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x65BA5380 key=231b0a87-e56b-1238-0aa6-005056873da33334445555 *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 3334445555 *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 7778889999 *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name LCS, number 7778889999, Calling oct3 0x00, oct_3a 0x81, Called number 3334445555 *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Peer tag 103 matched for incoming call *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 711 *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Media/sipSPICopyPeerDataToCCB: Firewall traversal is not enabled *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH *Mar 8 21:28:55.156: //-1/53D840FF8066/SIP/Info/sipSPIGetCallConfig: Media forking disabled *Mar 8 21:28:55.160: //-1/53D840FF8066/SIP/Info/sipSPIContinueNewMsgInvite: Calling name LCS, number 7778889999, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 3334445555, oct3 0x00 *Mar 8 21:28:55.160: //-1/53D840FF8066/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE *Mar 8 21:28:55.160: //-1/53D840FF8066/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0 *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1 SIP: (19) Attribute mid, level 1 instance 1 not found. *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.41.100.5 *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Media/sipSPISelectCodecVersion: g722-64 flavor of G722 codec will be used *Mar 8 21:28:55.160: //19/53D840FF8066/SIP/Info/sipSPIDoAudioNegotiation: Codec (g722-64) Negotiation Successful on Static Payload for m-line 1 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20 *Mar 8 21:28:55.164: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g722-64 ptime :20, codecbytes: 160 *Mar 8 21:28:55.164: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g722-64 codecbytes :160, ptime: 20 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g722-64 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved. *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full named event(NE) match in fmtp list of events. *Mar 8 21:28:55.164: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: NSE payload from X-cap = 0 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay *Mar 8 21:28:55.164: //19/53D840FF8066/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 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1 payload_type=9, codec_bytes=160, codec=g722-64, dtmf_relay=rtp-nte stream_type=voice+dtmf (1), dest_ip_address=10.41.100.2, dest_port=24384 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) *Mar 8 21:28:55.164: //19/53D840FF8066/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 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.41.100.5 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: callId 19 peer 0 flags 0x201 state STATE_IDLE *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: CallID 19, sdp 0x65EFE538 channels 0x65BA6640 *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/copy_channels: callId 19 size 0 ptr 0x657B2670) *Mar 8 21:28:55.164: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 9 mline 1 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Media/sipSPISelectCodecVersion: g722-64 flavor of G722 codec will be used *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g722-64 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/codec_found: Codec to be matched: 37 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 37 *Mar 8 21:28:55.168: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g722-64 codecbytes :160, ptime: 20 *Mar 8 21:28:55.168: //19/53D840FF8066/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 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo: failed to update call entry *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Adding codec 37 ptype 9 time 20, bytes 160 as channel 0 mline 1 ss 0 10.41.100.2:24384 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 0 mline 1 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/codec_found: Codec to be matched: 5 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=20, media_ndx=1 *Mar 8 21:28:55.168: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :20, codecbytes: 160 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo: failed to update call entry *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Adding codec 5 ptype 0 time 20, bytes 160 as channel 1 mline 1 ss 0 10.41.100.2:24384 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 8 mline 1 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/codec_found: Codec to be matched: 6 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=20, media_ndx=1 *Mar 8 21:28:55.168: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo: failed to update call entry *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Adding codec 6 ptype 8 time 20, bytes 160 as channel 2 mline 1 ss 0 10.41.100.2:24384 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Hndl ptype 101 mline 1 *Mar 8 21:28:55.168: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 19, dtmf = 6 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 37 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 6 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: callId 19 flags 0x300 state STATE_IDLE *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: Report initial call media *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC, ccb->pld.flags_ipip 0x201 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/copy_channels: callId 19 size 696 ptr 0x65EE0014) *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: CCSIP: Unable to report channel ind *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/ccsip_update_srtp_caps: 5054: Posting Remote SRTP caps to other callleg. *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPI_ipip_report_media_to_peer: do cc_api_caps_ind() *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : -1 Negotiated Codec : g722-64, bytes :160 Nego. Codec payload : 9 (tx), 9 (rx) Negotiated DTMF relay : rtp-nte Negotiated NTE payload : 101 (tx), 101 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [10.41.100.5]:0 Media Dest Addr/Port : [10.41.100.2]:24384 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPIHandleInviteMedia: Negotiated Codec : g722-64, bytes :160 Preferred Codec : g711ulaw, bytes :160 Preferred DTMF relay 1 : 6 Preferred DTMF relay 2 : 0 Negotiated DTMF relay : 6 Preferred and Negotiated NTE payloads: 101 101 Preferred and Negotiated NSE payloads: 100 0 Preferred and Negotiated Modem Relay: 0 0 Preferred and Negotiated Modem Relay GwXid: 1 0 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: Entry *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1 *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort *Mar 8 21:28:55.172: //19/53D840FF8066/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 16700 for stream 1 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=16700 *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 16700 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIUpdateSrcSdpVariablePart: SIP update src sdp, negoitated codec 37, payload type 9 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 101 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 231b0a87-e56b-1238-0aa6-005056873da3 *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotiated dtmf = 6, *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/sipSPIShrlCall: Check peer: 103 for Shared-Line call, callid: 19 *Mar 8 21:28:55.176: //19/53D840FF8066/SIP/Info/ccsip_set_bearer_capability: Bearer Capability: Speech (0x00) *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container *Mar 8 21:28:55.176: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 13 to table *Mar 8 21:28:55.180: //-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_create: created msg=0x65E5A6A0 with refCount = 1 *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Transport/sipSPITransportSendMessage: msg=0x65E5A6A0, addr=10.41.100.2, port=5080, sentBy_port=5080, is_req=0, transport=1, switch=0, callBack=0x00000000 *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 *Mar 8 21:28:55.180: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x65E5A6A0, addr=10.41.100.2, port=5080, connId=0 for UDP *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/State/sipSPIChangeState: 0x65BA5380 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_RECD_INVITE, SUBSTATE_NONE) *Mar 8 21:28:55.180: //19/53D840FF8066/SIP/Info/sipSPIProcessContactInfo: Previous Hop 10.41.100.2:5080 *Mar 8 21:28:55.184: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING *Mar 8 21:28:55.188: //19/53D840FF8066/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call. *Mar 8 21:28:55.188: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT *Mar 8 21:28:55.188: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 3 *Mar 8 21:28:55.188: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 7 *Mar 8 21:28:55.188: //19/53D840FF8066/SIP/Info/act_recdinvite_disconnect: Performing disconnect *Mar 8 21:28:55.192: //-1/xxxxxxxxxxxx/SIP/Info/httpish_msg_create: created msg=0x64DC9174 with refCount = 1 *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table. *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x65BA5380 key=231b0a87-e56b-1238-0aa6-005056873da328A88EC8-DDC *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Info/sipSPISendInviteResponse: Associated container=0x65D9D688 to Invite Response 404 *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Transport/sipSPITransportSendMessage: msg=0x64DC9174, addr=10.41.100.2, port=5080, sentBy_port=5080, is_req=0, transport=1, switch=0, callBack=0x61B0A9D4 *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 *Mar 8 21:28:55.192: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x64DC9174, addr=10.41.100.2, port=5080, connId=0 for UDP *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/Info/sentErrResDisconnecting: Sent an 3456XX Error Response *Mar 8 21:28:55.192: //19/53D840FF8066/SIP/State/sipSPIChangeState: 0x65BA5380 : State change from (STATE_RECD_INVITE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE) *Mar 8 21:28:55.196: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Sent:
... View more
Labels:
03-16-2020
12:18 PM
I have created the following dial-peer. This is only used for outbound faxing, inbound comes in via a fax2email server. When I attempt to dial out the call never connects and as far as I can tell it is because of a codec issue, but not really sure how to read the debug. dial-peer voice 102 voip description 11 Digit dialing translation-profile outgoing E164 destination-pattern 1[2-9]......... progress_ind setup enable 3 session protocol sipv2 session target dns:sip.flowroute.com session transport udp dtmf-relay rtp-nte codec g711ulaw fax-relay ecm disable fax-relay sg3-to-g3 fax protocol t38 version 0 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw ip qos dscp cs5 media ip qos dscp cs4 signaling no vad ################## Debug ################## Mar 16 17:46:56.297: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: VQM: gccb=0x0, gccb->callId=0, ccb->ccCallID=73 Mar 16 17:46:56.297: //73/F227CBEB80ED/SIP/State/sipSPIChangeStreamState: Stream (callid = 73) State changed from (STREAM_ADDING) to (STREAM_ACTIVE) Mar 16 17:46:56.297: //73/F227CBEB80ED/SIP/Info/sipSPIUpdateCallEntry: Call 73 set InfoType to SPEECH Mar 16 17:46:56.301: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Sent: INVITE sip:12345*17778889999@sip.provider.com:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK2669B Remote-Party-ID: <sip:13334445555@10.21.10.12>;party=calling;screen=no;privacy=off From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com> Date: Mon, 16 Mar 2020 17:46:56 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 4062694379-1726222826-2163060288-1187423458 User-Agent: Cisco-SIPGateway/IOS-15.2.1.T3 Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Max-Forwards: 70 Timestamp: 1584380816 Contact: <sip:13334445555@10.21.10.12:5060> Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 243 v=0 o=CiscoSystemsSIP-GW-UserAgent 9995 228 IN IP4 10.21.10.12 s=SIP Call c=IN IP4 10.21.10.12 t=0 0 m=audio 28022 RTP/AVP 0 101 c=IN IP4 10.21.10.12 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 Mar 16 17:46:56.797: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Info/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not an Forked leg.. Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Info/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added. Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off SIP: (73) Group (a= group line) attribute, level 65535 instance 1 not found. Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Info/sipSPISendInvite: Associated container=0x31CA3790 to Invite Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x2C520714, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0 Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Mar 16 17:46:56.797: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:69.18.5.8, rport:5060 with laddr: Mar 16 17:46:56.797: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x31C52D70 is already on connection=0x31598EF4 context_list Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2C520714 Mar 16 17:46:56.797: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2C520714, addr=69.18.5.8, port=5060, local_addr=, connId=2 for UDP Mar 16 17:46:56.797: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Sent: INVITE sip:12345*17778889999@sip.provider.com:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK2669B Remote-Party-ID: <sip:13334445555@10.21.10.12>;party=calling;screen=no;privacy=off From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com> Date: Mon, 16 Mar 2020 17:46:56 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 4062694379-1726222826-2163060288-1187423458 User-Agent: Cisco-SIPGateway/IOS-15.2.1.T3 Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Max-Forwards: 70 Timestamp: 1584380816 Contact: <sip:13334445555@10.21.10.12:5060> Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 243 v=0 o=CiscoSystemsSIP-GW-UserAgent 9995 228 IN IP4 10.21.10.12 s=SIP Call c=IN IP4 10.21.10.12 t=0 0 m=audio 28022 RTP/AVP 0 101 c=IN IP4 10.21.10.12 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 Mar 16 17:46:57.797: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Info/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not an Forked leg.. Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Info/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added. Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off SIP: (73) Group (a= group line) attribute, level 65535 instance 1 not found. Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Info/sipSPISendInvite: Associated container=0x31CA3790 to Invite Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x2C520714, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0 Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Mar 16 17:46:57.797: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:69.18.5.8, rport:5060 with laddr: Mar 16 17:46:57.797: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x31C52D70 is already on connection=0x31598EF4 context_list Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2C520714 Mar 16 17:46:57.797: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2C520714, addr=69.18.5.8, port=5060, local_addr=, connId=2 for UDP Mar 16 17:46:57.797: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Sent: INVITE sip:12345*17778889999@sip.provider.com:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK2669B Remote-Party-ID: <sip:13334445555@10.21.10.12>;party=calling;screen=no;privacy=off From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com> Date: Mon, 16 Mar 2020 17:46:57 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 4062694379-1726222826-2163060288-1187423458 User-Agent: Cisco-SIPGateway/IOS-15.2.1.T3 Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Max-Forwards: 70 Timestamp: 1584380817 Contact: <sip:13334445555@10.21.10.12:5060> Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 243 v=0 o=CiscoSystemsSIP-GW-UserAgent 9995 228 IN IP4 10.21.10.12 s=SIP Call c=IN IP4 10.21.10.12 t=0 0 m=audio 28022 RTP/AVP 0 101 c=IN IP4 10.21.10.12 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 Mar 16 17:46:58.313: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.18.5.8]:5060, local_address:[ - ] Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2BDDC50C Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2BDDC50C, addr=69.18.5.8, port=5060, local_addr=, connid=2, transport=UDP Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 2 Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 183 Session Progress From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Via: SIP/2.0/UDP 10.21.10.12:5060;rport=63967;received=107.211.204.153;branch=z9hG4bK2669B Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 CSeq: 101 INVITE Record-Route: <sip:69.18.5.7:5060;lr> Record-Route: <sip:69.18.5.8:5060;lr> Contact: <sip:+17778889999@107.17.5.140:5060> Content-Length: 171 Content-Type: application/sdp v=0 o=- 25797 29915 IN IP4 107.17.5.42 s=- c=IN IP4 107.17.5.42 t=0 0 m=audio 26864 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=maxptime:20 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Error/sipSPICheckReliableProvStringtag: Unable to access supported header values Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 26864 SIP: Attribute mid, level 1 instance 1 not found. Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec No Codec Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec: Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIDoPtimeNegotiation: No ptime present or multiple ptime attributes that can't be handled Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1 Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events. Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay Mar 16 17:46:58.317: //73/F227CBEB80ED/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 Mar 16 17:46:58.317: //73/F227CBEB80ED/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=107.17.5.42, dest_port=26864 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Media/sipSPIReplaceSDP: Main stream got changed & it's Flow Around Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_generic_event: Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP, event:E_SIP_IWF_EV_CALL_BRIDGE Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2 Mar 16 17:46:58.317: //73/F227CBEB80ED/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 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_handle_rcvd_sdp: Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_process_event: Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_OFFER_SENT, event:E_SIP_INVITE_RESP_SDP_RCVD Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_is_incoming_invite_resp_answer_valid: - 1 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_common_answer_rcvd_hdlr: Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_network_event: Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP, event:E_SIP_IWF_EV_RCVD_SDP Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sip_iwf_def_ed_rcvd_sdp_answer_hdlr: Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_DONE Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_ANSWER_COMPLETE Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ADDING (2) Stream address type : 1 Callid : 73 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 : [10.21.10.12]:28022 Media Dest Addr/Port : [107.17.5.42]:26864 Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container Mar 16 17:46:58.317: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/HandleSIP1xxSessionProgress: ccsip_api_call_cut_progress returned: SIP_SUCCESS Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/State/sipSPIChangeState: 0x31C52D70 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_NONE) Mar 16 17:46:58.317: //73/F227CBEB80ED/SIP/Info/HandleSIP1xxSessionProgress: Transaction Complete. Lock on Facilities released. Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_bridge: confID = 8, srcCallID = 73, dstCallID = 72 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 73/72 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=73, new streamcallid=73 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-TDM Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_generic_event: Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_CALL_BRIDGE Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_bridge: xcoder_attached = 0, xmitFunc = 625207628, ccb xmitFunc = 625207628 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_spi_check_call_locally_held: CCSIP: call is locally noton-hold Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 73) to the VOIP RTP library Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info laddr = 10.21.10.12, lport = 28022, raddr = 107.17.5.42, rport=26864, do_rtcp=TRUE src_callid = 73, dest_callid = 72, stream type = voice+dtmf, stream direction = SENDRECV media_ip_addr = 107.17.5.42, vrf tableid = 0 media_addr_type = 1 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: RTP session already created - update Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:307C6E04 Mar 16 17:46:58.321: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: VQM: gccb=0x0, gccb->callId=0, ccb->ccCallID=73 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled. Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sipSPI_ipip_is_escalation: local channels = 0, peer channels = 0 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPIGetNewLocalMediaDirection: New Remote Media Direction = SENDRECV Present Local Media Direction = SENDRECV New Local Media Direction = SENDRECV retVal = 0 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/State/sipSPIChangeStreamState: Stream (callid = 73) State changed from (STREAM_ADDING) to (STREAM_ACTIVE) Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_bridge: really can't find peer_stream for dtmf-relay interworking Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_peer_event: Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: 27 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_PEER_CAPS Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/is_mode_sip_sccp_do_video: Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_iwf_def_peer_caps_ind_hdlr: Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=73, current_seq_num=0x867 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=73, current_seq_num=0x424 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_iwf_def_process_caps_ind: Load DSP with negotiated codec: g711ulaw, Bytes=160 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_iwf_def_process_caps_ind: Set forking flag to 0x0 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 101, tx payload = 101 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=1, from CLI config=0 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=72 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Disabling Modem Relay... Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled Mar 16 17:46:58.321: //73/F227CBEB80ED/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 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: 1 Active Streams Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: Adding stream type (voice+dtmf) from media line 1 codec g711ulaw Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: caps.stream_count=1,caps.stream[0].stream_type=0x3, caps.stream_list.xmitFunc= Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: voip_rtp_xmit, caps.stream_list.context= Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: 0x2AC51700 (gccb) Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_iwf_def_process_caps_ind: Load DSP with codec : g711ulaw, Bytes=160, payload = 0 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_iwf_def_process_caps_ind: ccsip_caps_ind: ccb->pld.flags_ipip = 0x201 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_iwf_def_process_caps_ind: Calling cc_api_caps_ack() Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 7 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IPIPMS:cur_container:ccsip_ipip_media_service_main_container, cur_state:S_IPIP_MEDIA_SERV_STATE_IDLE, event:E_IPIP_MEDIA_SERV_EV_PEER_CAPS_IND Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_peer_event: Return value : SIP_IWF_SUCCESS Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_map_cc_return_code: Mapping SIP_IWF_SUCCESS Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_peer_event: Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: 28 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_PEER_CAPS_ACK, Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_iwf_def_peer_caps_ack_hdlr: Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/sip_iwf_tdm_process_caps_ack: Set forking flag to 0x7 Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_peer_event: Return value : SIP_IWF_SUCCESS Mar 16 17:46:58.321: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_map_cc_return_code: Mapping SIP_IWF_SUCCESS Mar 16 17:46:58.745: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.18.5.8]:5060, local_address:[ - ] Mar 16 17:46:58.745: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Mar 16 17:46:58.745: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2BDDC50C Mar 16 17:46:58.745: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2BDDC50C, addr=69.18.5.8, port=5060, local_addr=, connid=2, transport=UDP Mar 16 17:46:58.745: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 2 Mar 16 17:46:58.745: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Via: SIP/2.0/UDP 10.21.10.12:5060;rport=63967;received=107.211.204.153;branch=z9hG4bK2669B Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 CSeq: 101 INVITE Record-Route: <sip:69.18.5.7:5060;lr> Record-Route: <sip:69.18.5.8:5060;lr> Contact: <sip:+17778889999@107.17.5.140:5060> Session-Expires: 3600;refresher=uas Content-Length: 171 Content-Type: application/sdp Supported: timer v=0 o=- 25797 29915 IN IP4 107.17.5.42 s=- c=IN IP4 107.17.5.42 t=0 0 m=audio 26864 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=maxptime:20 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIhandle200OKInvite: Transaction active. Facilities will be queued. Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIhandle200OKInvite: *** This ccb is the parent Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_generic_event: Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_CALL_BRIDGE Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Error/sipSPIProcessNotifyCallInfoHeader: Call-Info header with for Unsolicited Notify Absent,Disabling Unsolicited Notifies Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:200, container:31CA3EC8 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Session-Expires value: 3600 refresher: uas Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLSRRespRcvd: Session expires params received starting the timer based on the refresher Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLStartSessionTimer: Started Session Expiry Timer with duration:3568000 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLMain: SE: 3600;refresher:uas peer refresher:none, flags:0, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 26864 SIP: Attribute mid, level 1 instance 1 not found. Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec No Codec Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 96 for Codec: Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec No Codec Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec: Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIDoPtimeNegotiation: No ptime present or multiple ptime attributes that can't be handled Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1 Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events. Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay Mar 16 17:46:58.749: //73/F227CBEB80ED/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 Mar 16 17:46:58.749: //73/F227CBEB80ED/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=107.17.5.42, dest_port=26864 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Media/sipSPICompareStreams: stream 1 dest_port: old=26864 new=26864 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Media/sipSPIGetNewLocalMediaDirection: New Remote Media Direction = SENDRECV Present Local Media Direction = SENDRECV New Local Media Direction = SENDRECV retVal = 0 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Media/sipSPICompareStreams: Flags set for stream 1: RTP_CHANGE=No CAPS_CHANGE=No RSVP_ADDR_CHANGE=No RSVP_MEDIA_CHANGE=No Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Media/sipSPICompareSDP: Flags set for call: NEW_MEDIA=No DSPDNLD_REQD=No IPIP_MEDIA=No Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Media/sipSPIReplaceSDP: Main stream got changed & it's Flow Around Mar 16 17:46:58.749: //73/F227CBEB80ED/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 : No DSP DNLD Reqd : No Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_handle_rcvd_sdp: Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_process_event: Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_OFFER_ANSWER_COMPLETE, event:E_SIP_INVITE_RESP_SDP_RCVD Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_is_invite_resp_ignored: Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_ignore_hdlr: S_SIP_EARLY_DIALOG_OFFER_ANSWER_COMPLETE, E_SIP_INVITE_RESP_SDP_RCVD Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_ACTIVE (5) Stream address type : 1 Callid : 73 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 : [10.21.10.12]:28022 Media Dest Addr/Port : [107.17.5.42]:26864 Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connect_media returned: SIP_SUCCESS Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/State/sipSPIChangeState: 0x31C52D70 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_NONE) Mar 16 17:46:58.749: //73/F227CBEB80ED/SIP/Info/sipSPIQoSRevertBW: Entry Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container Mar 16 17:46:58.749: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/sipSPIShrlCall: Check peer: 102 for Shared-Line call, callid: 73 Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/sipSPIOptionsPing: Session Timer negotiated, not doing Options Ping Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled. Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/sipSPIhandle200OKInvite: ccsip_api_call_connected returned: SIP_SUCCESS Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_handle_call_active: Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_process_event: Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_OFFER_ANSWER_COMPLETE, event:E_SIP_DIALOG_ESTD Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_dialog_established_hdlr: Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_generic_event: Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_CALL_ACTIVE Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/is_mode_sip_sip: Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/is_mode_sip_h323: Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/is_mode_sip_h32x: Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/is_mode_sip_default: Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_set_tdm_ip_call_active: Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_default_mid_dialog_container Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_MID_DIALOG_IDLE Mar 16 17:46:58.753: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddRouteHeaders: status = TRUE Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Info/sipSPISendAck: Associated container=0x31CA3738 to Ack Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x2AC56328, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x2534B320 Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:46:58.753: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0ACK sip:+17778889999@107.17.5.140:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK271F07 From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Date: Mon, 16 Mar 2020 17:46:57 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Max-Forwards: 70 CSeq: 101 ACK Allow-Events: telephone-event Content-Length: 0 Mar 16 17:47:00.885: //73/F227CBEB80ED/SIP/Info/ccsip_indicate_rt_packet_stats: Processing stats for callid=73, proc_id=9 Mar 16 17:47:03.701: //73/F227CBEB80ED/SIP/Info/ccsip_indicate_rt_packet_stats: Processing stats for callid=73, proc_id=9 Mar 16 17:47:07.253: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_T38_FAX_START Mar 16 17:47:07.253: //-1/xxxxxxxxxxxx/SIP/Event/ccsip_call_feature: Ignoring non-hookflash feature event (0x00000001) Mar 16 17:47:07.253: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 19 Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/act_active_t38_fax_start: Entering T.38 mode Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/act_active_t38_fax_start: Transaction active. CCAPI events will be queued. Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/sipSPIUpdateSDPQoSAttributes: Entry Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/sipSPIUpdateStreamQoSAttributes: 9 a-line(s) found for stream 1 Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/sipSPICacheEvent: Clear UPDATE flags Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/State/sipSPIChangeState: 0x31C52D70 : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_SEND_MIDCALL_INVITE_PENDING, SUBSTATE_NONE) Mar 16 17:47:07.253: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 69.18.5.8,Port 5060, Transport 1, SentBy Port 5060 Mar 16 17:47:07.253: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:0, container:31CA3BB0 Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLSRReqSend: Sending previously negotiated session expires params Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLMain: SE: 3600;refresher:uas peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_handle_sent_sdp: Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_process_event: Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_MID_DIALOG_IDLE, event:E_SIP_INVITE_SDP_SENT Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_is_invite_offer_valid: - 1 Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_common_offer_sent_hdlr: Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_network_event: Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_mid_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_SENT_SDP Mar 16 17:47:07.253: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2 Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_MID_DIALOG_OFFER_SENT Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Info/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not an Forked leg.. Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Info/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added. Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off Mar 16 17:47:07.257: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddRouteHeaders: status = TRUE Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> SIP: (73) Group (a= group line) attribute, level 65535 instance 1 not found. Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Info/sipSPISendInvite: Associated container=0x31CA3BB0 to Invite Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x31CFAD18, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x253492B0 Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Mar 16 17:47:07.257: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:69.18.5.8, rport:5060 with laddr: Mar 16 17:47:07.257: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x31C52D70 is already on connection=0x31598EF4 context_list Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x31CFAD18 Mar 16 17:47:07.257: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x31CFAD18, addr=69.18.5.8, port=5060, local_addr=, connId=2 for UDP Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Info/sentInviteRequest: Sent Invite in state STATE_SEND_MIDCALL_INVITE_PENDING Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/State/sipSPIChangeState: 0x31C52D70 : State change from (STATE_SEND_MIDCALL_INVITE_PENDING, SUBSTATE_NONE) to (STATE_SENT_MIDCALL_INVITE, SUBSTATE_NONE) Mar 16 17:47:07.257: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Sent: INVITE sip:+17778889999@107.17.5.140:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK28185 Remote-Party-ID: <sip:13334445555@10.21.10.12>;party=calling;screen=no;privacy=off From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Date: Mon, 16 Mar 2020 17:47:07 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 4062694379-1726222826-2163060288-1187423458 User-Agent: Cisco-SIPGateway/IOS-15.2.1.T3 Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 102 INVITE Max-Forwards: 70 Timestamp: 1584380827 Contact: <sip:13334445555@10.21.10.12:5060> Expires: 180 Allow-Events: telephone-event Session-Expires: 3600;refresher=uas Content-Type: application/sdp Content-Length: 314 v=0 o=CiscoSystemsSIP-GW-UserAgent 9995 229 IN IP4 10.21.10.12 s=SIP Call c=IN IP4 10.21.10.12 t=0 0 m=image 28022 udptl t38 c=IN IP4 10.21.10.12 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:320 a=T38FaxUdpEC:t38UDPRedundancy Mar 16 17:47:07.257: //-1/xxxxxxxxxxxx/SIP/Event/ccsip_call_feature: Ignoring non-hookflash feature event (0x00000001) Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.18.5.8]:5060, local_address:[ - ] Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Info/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not an Forked leg.. Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Info/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added. Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddRouteHeaders: status = TRUE Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> SIP: (73) Group (a= group line) attribute, level 65535 instance 1 not found. Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Info/sipSPISendInvite: Associated container=0x31CA3BB0 to Invite Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x31CFAD18, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0 Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:69.18.5.8, rport:5060 with laddr: Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x31C52D70 is already on connection=0x31598EF4 context_list Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x31CFAD18 Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x31CFAD18, addr=69.18.5.8, port=5060, local_addr=, connId=2 for UDP Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2BDDC50C Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2BDDC50C, addr=69.18.5.8, port=5060, local_addr=, connid=2, transport=UDP Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 2 Mar 16 17:47:08.081: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Mar 16 17:47:08.081: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Via: SIP/2.0/UDP 10.21.10.12:5060;rport=63967;received=107.211.204.153;branch=z9hG4bK28185 Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 CSeq: 102 INVITE Record-Route: <sip:69.18.5.7:5060;lr> Record-Route: <sip:69.18.5.8:5060;lr;did=945.c6e4> Contact: <sip:+17778889999@107.17.5.140:5060> Session-Expires: 3600;refresher=uas Content-Length: 171 Content-Type: application/sdp Supported: timer v=0 o=- 25797 29916 IN IP4 107.17.5.42 s=- c=IN IP4 107.17.5.42 t=0 0 m=image 26864 udptl t38 a=T38FaxRateManagement:transferredTCF a=T38FaxUdpEC:t38UDPRedundancy Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/ccsip_api_response_answer: ccsip_api_response_answer. Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:200, container:31CA35D8 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Session-Expires value: 3600 refresher: uas Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLSRRespRcvd: Session expires params received starting the timer based on the refresher Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLStartSessionTimer: Started Session Expiry Timer with duration:3568000 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLMain: SE: 3600;refresher:uas peer refresher:none, flags:0, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 26864 SIP: Attribute mid, level 1 instance 1 not found. Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIDoFaxAttributeNegotiation: No remote bit rate, Using our bit rate: 14400 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPIDoFaxMediaNegotiation: T.38 negotiated Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPICompareStreams: stream 1 dest_port: old=26864 new=26864 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIGetNewLocalMediaDirection: New Remote Media Direction = SENDRECV Present Local Media Direction = SENDRECV New Local Media Direction = SENDRECV retVal = 0 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPICompareMediaType: Media type switching from 0 to 11 for stream 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPICompareStreams: negotiated codec changed from g711ulaw to T38Fax Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPICompareStreams: negotiated dtmf relay changed from rtp-nte to inband-voice Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPICompareStreams: Flags set for stream 1: RTP_CHANGE=Yes CAPS_CHANGE=Yes RSVP_ADDR_CHANGE=No RSVP_MEDIA_CHANGE=Yes Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPICompareSDP: Flags set for call: NEW_MEDIA=Yes DSPDNLD_REQD=Yes IPIP_MEDIA=Yes Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIRSVPCompareSDP: Media Type Change Identified Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIRSVPCompareSDP: Media Codec Change Identified Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIRSVPCompareSDP: Media Offer Changed Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIReplaceSDP: Main stream got changed & it's Flow Around Mar 16 17:47:08.085: //73/F227CBEB80ED/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 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_handle_rcvd_sdp: Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_process_event: Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_MID_DIALOG_OFFER_SENT, event:E_SIP_INVITE_RESP_SDP_RCVD Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_is_incoming_invite_resp_answer_valid: - 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_common_answer_rcvd_hdlr: Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_network_event: Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_mid_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_RCVD_SDP Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_MID_DIALOG_IDLE Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_CHANGING (4) Stream address type : 1 Callid : -1 Negotiated Codec : T38Fax, bytes :20 Nego. Codec payload : 255 (tx), 255 (rx) Negotiated DTMF relay : inband-voice Negotiated NTE payload : 0 (tx), 0 (rx) Negotiated CN payload : 0 Media Srce Addr/Port : [10.21.10.12]:28022 Media Dest Addr/Port : [107.17.5.42]:26864 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIDeleteStream: Deleting stream 1 from the VOIP RTP library Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIDestroyRtpSession: stream:31CF0CD8 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 73) to the VOIP RTP library Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info laddr = 10.21.10.12, lport = 28022, raddr = 107.17.5.42, rport=26864, do_rtcp=FALSE src_callid = 73, dest_callid = 72, stream type = voice+dtmf, stream direction = SENDRECV media_ip_addr = 107.17.5.42, vrf tableid = 0 media_addr_type = 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPICreateRtpSession: sess: 2BA2015C do_rtcp:0 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPICreateRtpSession: stun is disabled Mar 16 17:47:08.085: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: VQM: gccb=0x0, gccb->callId=0, ccb->ccCallID=73 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPI_ipip_is_escalation: local channels = 0, peer channels = 0 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIGetNewLocalMediaDirection: New Remote Media Direction = SENDRECV Present Local Media Direction = SENDRECV New Local Media Direction = SENDRECV retVal = 0 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/State/sipSPIChangeStreamState: Stream (callid = 73) State changed from (STREAM_CHANGING) to (STREAM_ACTIVE) Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info laddr = 10.21.10.12, lport = 28022, raddr = 107.17.5.42, rport=26864, do_rtcp=FALSE src_callid = 73, dest_callid = 72, stream type = voice+dtmf, stream direction = SENDRECV media_ip_addr = 107.17.5.42, vrf tableid = 0 media_addr_type = 1 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: RTP session already created - update Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:31CF0CD8 Mar 16 17:47:08.085: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: VQM: gccb=0x0, gccb->callId=0, ccb->ccCallID=73 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPI_ipip_is_escalation: local channels = 0, peer channels = 0 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Media/sipSPIGetNewLocalMediaDirection: New Remote Media Direction = SENDRECV Present Local Media Direction = SENDRECV New Local Media Direction = SENDRECV retVal = 0 Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/sipSPIProcessMediaChanges: DSPDNLD Reqd is true. Call DoCapsInd Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_generic_event: Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_mid_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_LOCAL_CAPS_IND Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:47:08.085: //73/F227CBEB80ED/SIP/Info/is_mode_sip_sccp_do_video: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sip_iwf_common_local_caps_hdlr: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=73, current_seq_num=0x424 Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=73, current_seq_num=0x22AB Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_do_caps_ind_internal: Load DSP with codec: T38Fax, Bytes=20 Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: 1 Active Streams Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: Adding stream type (voice+dtmf) from media line 1 codec T38Fax Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: caps.stream_count=1,caps.stream[0].stream_type=0x3, caps.stream_list.xmitFunc= Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: voip_rtp_xmit, caps.stream_list.context= Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: 0x2AC51700 (gccb) Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE_AND_OOB Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0 Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=72 Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Disabling Modem Relay... Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled Mar 16 17:47:08.089: //73/F227CBEB80ED/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 Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_api_response_answer: Modified QoS params INVITE Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_generic_event: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_mid_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_XACTION_RESUME Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sip_iwf_common_ignore_hdlr: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sact_sent_mid_invite_new_message_response: ccsip_api_response_answer return value: SIP_SUCCESS Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_handle_call_active: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_process_event: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_MID_DIALOG_IDLE, event:E_SIP_DIALOG_ESTD Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_dialog_established_hdlr: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_generic_event: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_mid_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_CALL_ACTIVE Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/is_mode_sip_sip: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/is_mode_sip_h323: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/is_mode_sip_h32x: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/is_mode_sip_default: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_set_tdm_ip_call_active: Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_default_mid_dialog_container Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sipSPIPushOrigRequestContainerIntoHolder: Request Container Holder is above threshold...trimming Mar 16 17:47:08.089: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddRouteHeaders: status = TRUE Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sipSPISendAck: Associated container=0x31CA3EC8 to Ack Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x2C546A88, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x2534B320 Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Mar 16 17:47:08.089: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:69.18.5.8, rport:5060 with laddr: Mar 16 17:47:08.089: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x31C52D70 is already on connection=0x31598EF4 context_list Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2C546A88 Mar 16 17:47:08.089: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2C546A88, addr=69.18.5.8, port=5060, local_addr=, connId=2 for UDP Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/State/sipSPIChangeState: 0x31C52D70 : State change from (STATE_SENT_MIDCALL_INVITE, SUBSTATE_NONE) to (STATE_ACTIVE, SUBSTATE_NONE) Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Info/sipSPISendAckForMidCallInvite: Transaction Complete. Lock on Facilities released. Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Call/sipSPICallInfo: The Call Setup Information is: Call Control Block (CCB) : 0x31C52D70 State of The Call : STATE_ACTIVE TCP Sockets Used : NO Calling Number : 13334445555 Called Number : 12345*17778889999 Source IP Address (Sig ): 10.21.10.12 Destn SIP Req Addr:Port : 69.18.5.8:5060 Destn SIP Resp Addr:Port : 69.18.5.8:5060 Destination Name : sip.provider.com Mar 16 17:47:08.089: //73/F227CBEB80ED/SIP/Call/sipSPIMediaCallInfo: Number of Media Streams: 1 Media Stream : 1 Negotiated Codec : T38Fax Negotiated Codec Bytes : 20 Nego. Codec payload : 255 (tx), 255 (rx) Negotiated Dtmf-relay : 0 Dtmf-relay Payload : 0 (tx), 0 (rx) Source IP Address (Media): 10.21.10.12 Source IP Port (Media): 28022 Destn IP Address (Media): 107.17.5.42 Destn IP Port (Media): 26864 Orig Destn IP Address:Port (Media): [ - ]:0 Mar 16 17:47:08.101: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CODEC_LOCAL_DNLD_DONE Mar 16 17:47:08.101: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 21 Mar 16 17:47:08.101: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Sent: INVITE sip:+17778889999@107.17.5.140:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK28185 Remote-Party-ID: <sip:13334445555@10.21.10.12>;party=calling;screen=no;privacy=off From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Date: Mon, 16 Mar 2020 17:47:08 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 4062694379-1726222826-2163060288-1187423458 User-Agent: Cisco-SIPGateway/IOS-15.2.1.T3 Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 102 INVITE Max-Forwards: 70 Timestamp: 1584380828 Contact: <sip:13334445555@10.21.10.12:5060> Expires: 180 Allow-Events: telephone-event Session-Expires: 3600;refresher=uas Content-Type: application/sdp Content-Length: 314 v=0 o=CiscoSystemsSIP-GW-UserAgent 9995 229 IN IP4 10.21.10.12 s=SIP Call c=IN IP4 10.21.10.12 t=0 0 m=image 28022 udptl t38 c=IN IP4 10.21.10.12 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:320 a=T38FaxUdpEC:t38UDPRedundancy Mar 16 17:47:08.101: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Sent: ACK sip:+17778889999@107.17.5.140:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK29169C From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Date: Mon, 16 Mar 2020 17:47:08 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Max-Forwards: 70 CSeq: 102 ACK Allow-Events: telephone-event Content-Length: 0 Mar 16 17:47:08.265: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.18.5.8]:5060, local_address:[ - ] Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2BDDC50C Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2BDDC50C, addr=69.18.5.8, port=5060, local_addr=, connid=2, transport=UDP Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 2 Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Via: SIP/2.0/UDP 10.21.10.12:5060;rport=63967;received=107.211.204.153;branch=z9hG4bK28185 Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 CSeq: 102 INVITE Record-Route: <sip:69.18.5.7:5060;lr> Record-Route: <sip:69.18.5.8:5060;lr;did=945.c6e4> Contact: <sip:+17778889999@107.17.5.140:5060> Session-Expires: 3600;refresher=uas Content-Length: 171 Content-Type: application/sdp Supported: timer v=0 o=- 25797 29916 IN IP4 107.17.5.42 s=- c=IN IP4 107.17.5.42 t=0 0 m=image 26864 udptl t38 a=T38FaxRateManagement:transferredTCF a=T38FaxUdpEC:t38UDPRedundancy Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddRouteHeaders: status = TRUE Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Info/sipSPISendAck: Associated container=0x31CA3EC8 to Ack Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x31CFAD18, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0 Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:69.18.5.8, rport:5060 with laddr: Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x31C52D70 is already on connection=0x31598EF4 context_list Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x31CFAD18 Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x31CFAD18, addr=69.18.5.8, port=5060, local_addr=, connId=2 for UDP Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Sent: ACK sip:+17778889999@107.17.5.140:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK29169C From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Date: Mon, 16 Mar 2020 17:47:08 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Max-Forwards: 70 CSeq: 102 ACK Allow-Events: telephone-event Content-Length: 0 Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.18.5.8]:5060, local_address:[ - ] Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2BDDC50C Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2BDDC50C, addr=69.18.5.8, port=5060, local_addr=, connid=2, transport=UDP Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 2 Mar 16 17:47:08.269: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Mar 16 17:47:08.269: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Via: SIP/2.0/UDP 10.21.10.12:5060;rport=63967;received=107.211.204.153;branch=z9hG4bK28185 Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 CSeq: 102 INVITE Record-Route: <sip:69.18.5.7:5060;lr> Record-Route: <sip:69.18.5.8:5060;lr;did=945.c6e4> Contact: <sip:+17778889999@107.17.5.140:5060> Session-Expires: 3600;refresher=uas Content-Length: 171 ContACK sip:+17778889999@107.17.5.140:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK29169C From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Date: Mon, 16 Mar 2020 17:47:08 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Max-Forwards: 70 CSeq: 102 ACK Allow-Events: telephone-event Content-Length: 0 Mar 16 17:47:32.705: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_T38_FAX_DONE Mar 16 17:47:32.705: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 20 Mar 16 17:47:32.705: //73/F227CBEB80ED/SIP/Info/act_active_t38_fax_done: Exiting T.38 mode Mar 16 17:47:32.705: //73/F227CBEB80ED/SIP/Info/act_active_t38_fax_done: Transaction active. CCAPI events will be queued. Mar 16 17:47:32.705: //73/F227CBEB80ED/SIP/Info/sipSPIUpdateSDPQoSAttributes: Entry Mar 16 17:47:32.705: //73/F227CBEB80ED/SIP/Info/sipSPIUpdateStreamQoSAttributes: 4 a-line(s) found for stream 1 Mar 16 17:47:32.705: //73/F227CBEB80ED/SIP/Info/sipSPIStopRequestPendingTimer: Stopping Request Pending Timer Mar 16 17:47:32.705: //73/F227CBEB80ED/SIP/Info/sipSPICacheEvent: Free'd ccb's cached Event Mar 16 17:47:32.705: //73/F227CBEB80ED/SIP/Info/sipSPICacheEvent: Clear UPDATE flags Mar 16 17:47:32.705: //73/F227CBEB80ED/SIP/State/sipSPIChangeState: 0x31C52D70 : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_SEND_MIDCALL_INVITE_PENDING, SUBSTATE_NONE) Mar 16 17:47:32.705: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 69.18.5.8,Port 5060, Transport 1, SentBy Port 5060 Mar 16 17:47:32.705: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:0, container:31CA3108 Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLSRReqSend: Sending previously negotiated session expires params Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLMain: SE: 3600;refresher:uas peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_handle_sent_sdp: Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_process_event: Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_MID_DIALOG_IDLE, event:E_SIP_INVITE_SDP_SENT Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_is_invite_offer_valid: - 1 Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_common_offer_sent_hdlr: Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_network_event: Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_mid_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_SENT_SDP Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2 Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_MID_DIALOG_OFFER_SENT Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/sipSPIPushOrigRequestContainerIntoHolder: Request Container Holder is above threshold...trimming Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not an Forked leg.. Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added. Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Event/sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off Mar 16 17:47:32.709: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddRouteHeaders: status = TRUE Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Group (a= group line) attribute, level 65535 instance 1 not found. Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/sipSPISendInvite: Associated container=0x31CA3108 to Invite Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x2AC2EC24, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x253492B0 Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Mar 16 17:47:32.709: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:69.18.5.8, rport:5060 with laddr: Mar 16 17:47:32.709: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x31C52D70 is already on connection=0x31598EF4 context_list Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x2AC2EC24 Mar 16 17:47:32.709: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x2AC2EC24, addr=69.18.5.8, port=5060, local_addr=, connId=2 for UDP Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Info/sentInviteRequest: Sent Invite in state STATE_SEND_MIDCALL_INVITE_PENDING Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/State/sipSPIChangeState: 0x31C52D70 : State change from (STATE_SEND_MIDCALL_INVITE_PENDING, SUBSTATE_NONE) to (STATE_SENT_MIDCALL_INVITE, SUBSTATE_NONE) Mar 16 17:47:32.709: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Sent: INVITE sip:+17778889999@107.17.5.140:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK2A25A4 Remote-Party-ID: <sip:13334445555@10.21.10.12>;party=calling;screen=no;privacy=off From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Date: Mon, 16 Mar 2020 17:47:32 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 4062694379-1726222826-2163060288-1187423458 User-Agent: Cisco-SIPGateway/IOS-15.2.1.T3 Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 103 INVITE Max-Forwards: 70 Timestamp: 1584380852 Contact: <sip:13334445555@10.21.10.12:5060> Expires: 180 Allow-Events: telephone-event Session-Expires: 3600;refresher=uas Content-Type: application/sdp Content-Length: 243 v=0 o=CiscoSystemsSIP-GW-UserAgent 9995 229 IN IP4 10.21.10.12 s=SIP Call c=IN IP4 10.21.10.12 t=0 0 m=audio 28022 RTP/AVP 0 101 c=IN IP4 10.21.10.12 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 Mar 16 17:47:32.717: //73/F227CBEB80ED/SIP/Info/ccsip_modify_media_ind: codec=0x1 modem_redundancy=0 callID 73 peer callID 72 Mar 16 17:47:32.717: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_MEDIA_CHANGED Mar 16 17:47:32.717: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 18 Mar 16 17:47:32.717: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SPI_EVENT Mar 16 17:47:32.717: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLMain: SE: 3600;refresher:uas peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Mar 16 17:47:32.717: //73/F227CBEB80ED/SIP/Info/sipSPIEnqueueBufferEvent: Event SIPSPI_EV_CC_CALL_MEDIA_CHANGED queued on buffer queue. Mar 16 17:47:32.925: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.18.5.8]:5060, local_address:[ - ] Mar 16 17:47:32.925: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Mar 16 17:47:32.925: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2BDDC50C Mar 16 17:47:32.925: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2BDDC50C, addr=69.18.5.8, port=5060, local_addr=, connid=2, transport=UDP Mar 16 17:47:32.925: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 2 Mar 16 17:47:32.925: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Mar 16 17:47:32.925: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Via: SIP/2.0/UDP 10.21.10.12:5060;rport=63967;received=107.211.204.153;branch=z9hG4bK2A25A4 Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 CSeq: 103 INVITE Record-Route: <sip:69.18.5.7:5060;lr> Record-Route: <sip:69.18.5.8:5060;lr;did=945.c6e4> Contact: <sip:+17778889999@107.17.5.140:5060> Session-Expires: 3600;refresher=uas Content-Length: 171 Content-Type: application/sdp Supported: timer v=0 o=- 25797 29917 IN IP4 107.17.5.42 s=- c=IN IP4 107.17.5.42 t=0 0 m=audio 26864 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=maxptime:20 Mar 16 17:47:32.925: //73/F227CBEB80ED/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX Mar 16 17:47:32.925: //73/F227CBEB80ED/SIP/Info/ccsip_api_response_answer: ccsip_api_response_answer. Mar 16 17:47:32.925: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP Mar 16 17:47:32.925: //73/F227CBEB80ED/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:200, container:31CA3CB8 Mar 16 17:47:32.925: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Session-Expires value: 3600 refresher: uas Mar 16 17:47:32.925: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLSRRespRcvd: Session expires params received starting the timer based on the refresher Mar 16 17:47:32.925: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLStartSessionTimer: Started Session Expiry Timer with duration:3568000 Mar 16 17:47:32.925: //73/F227CBEB80ED/SIP/Info/Session-Timer/sipSTSLMain: SE: 3600;refresher:uas peer refresher:none, flags:0, posted event:E_STSL_INVALID_PEER_EVENT, reason:4 Configured SE:1800, Configured Min-SE:1800 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 26864 SIP: Attribute mid, level 1 instance 1 not found. Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec No Codec Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 96 for Codec: Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved as its in use by other codec No Codec Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101 Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec: Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIDoPtimeNegotiation: No ptime present or multiple ptime attributes that can't be handled Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1 Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96 Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events. Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay Mar 16 17:47:32.929: //73/F227CBEB80ED/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 Mar 16 17:47:32.929: //73/F227CBEB80ED/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=107.17.5.42, dest_port=26864 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING) Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPICompareStreams: stream 1 dest_port: old=26864 new=26864 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIGetNewLocalMediaDirection: New Remote Media Direction = SENDRECV Present Local Media Direction = SENDRECV New Local Media Direction = SENDRECV retVal = 0 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPICompareMediaType: Media type switching from 11 to 0 for stream 1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPICompareStreams: negotiated codec changed from T38Fax to g711ulaw Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPICompareStreams: negotiated dtmf relay changed from inband-voice to rtp-nte Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPICompareStreams: Flags set for stream 1: RTP_CHANGE=Yes CAPS_CHANGE=Yes RSVP_ADDR_CHANGE=No RSVP_MEDIA_CHANGE=Yes Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPICompareSDP: Flags set for call: NEW_MEDIA=Yes DSPDNLD_REQD=Yes IPIP_MEDIA=Yes Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIRSVPCompareSDP: Media Type Change Identified Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIRSVPCompareSDP: Media Codec Change Identified Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIRSVPCompareSDP: Media Offer Changed Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIReplaceSDP: Main stream got changed & it's Flow Around Mar 16 17:47:32.929: //73/F227CBEB80ED/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 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_handle_rcvd_sdp: Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_process_event: Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_MID_DIALOG_OFFER_SENT, event:E_SIP_INVITE_RESP_SDP_RCVD Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_is_incoming_invite_resp_answer_valid: - 1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_common_answer_rcvd_hdlr: Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_network_event: Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_mid_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_RCVD_SDP Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_MID_DIALOG_IDLE Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIUpdCallWithSdpInfo: Stream type : voice+dtmf Media line : 1 State : STREAM_CHANGING (4) Stream address type : 1 Callid : -1 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 : [10.21.10.12]:28022 Media Dest Addr/Port : [107.17.5.42]:26864 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIDeleteStream: Deleting stream 1 from the VOIP RTP library Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIDestroyRtpSession: stream:307C6E04 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 73) to the VOIP RTP library Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.21.10.12 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info laddr = 10.21.10.12, lport = 28022, raddr = 107.17.5.42, rport=26864, do_rtcp=TRUE src_callid = 73, dest_callid = 72, stream type = voice+dtmf, stream direction = SENDRECV media_ip_addr = 107.17.5.42, vrf tableid = 0 media_addr_type = 1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPICreateRtpSession: sess: 2BA2015C do_rtcp:1 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPICreateRtpSession: stun is disabled Mar 16 17:47:32.929: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: VQM: gccb=0x0, gccb->callId=0, ccb->ccCallID=73 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled. Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Info/sipSPI_ipip_is_escalation: local channels = 0, peer channels = 0 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/Media/sipSPIGetNewLocalMediaDirection: New Remote Media Direction = SENDRECV Present Local Media Direction = SENDRECV New Local Media Direction = SENDRECV retVal = 0 Mar 16 17:47:32.929: //73/F227CBEB80ED/SIP/State/sipSPIChangeStreamState: Stream (callid = 73) State changed from (STREAM_CHANGING) to (STREAM_ACTIVE) Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info laddr = 10.21.10.12, lport = 28022, raddr = 107.17.5.42, rport=26864, do_rtcp=TRUE src_callid = 73, dest_callid = 72, stream type = voice+dtmf, stream direction = SENDRECV media_ip_addr = 107.17.5.42, vrf tableid = 0 media_addr_type = 1 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtcpSession: RTP session already created - update Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:307C6E04 Mar 16 17:47:32.933: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: VQM: gccb=0x0, gccb->callId=0, ccb->ccCallID=73 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled. Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sipSPI_ipip_is_escalation: local channels = 0, peer channels = 0 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Media/sipSPIGetNewLocalMediaDirection: New Remote Media Direction = SENDRECV Present Local Media Direction = SENDRECV New Local Media Direction = SENDRECV retVal = 0 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sipSPIProcessMediaChanges: DSPDNLD Reqd is true. Call DoCapsInd Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_generic_event: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_mid_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_LOCAL_CAPS_IND Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/is_mode_sip_sccp_do_video: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sip_iwf_common_local_caps_hdlr: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=73, current_seq_num=0x22AB Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=73, current_seq_num=0xF2B Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_do_caps_ind_internal: Load DSP with codec: g711ulaw, Bytes=160 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: 1 Active Streams Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: Adding stream type (voice+dtmf) from media line 1 codec g711ulaw Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: caps.stream_count=1,caps.stream[0].stream_type=0x3, caps.stream_list.xmitFunc= Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: voip_rtp_xmit, caps.stream_list.context= Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Media/sipSPISetStreamInfo: 0x2AC51700 (gccb) Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 101, tx payload = 101 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=72 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Disabling Modem Relay... Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled Mar 16 17:47:32.933: //73/F227CBEB80ED/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 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_api_response_answer: Modified QoS params INVITE Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_generic_event: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_mid_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_XACTION_RESUME Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sip_iwf_common_ignore_hdlr: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sact_sent_mid_invite_new_message_response: ccsip_api_response_answer return value: SIP_SUCCESS Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_handle_call_active: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_process_event: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_MID_DIALOG_IDLE, event:E_SIP_DIALOG_ESTD Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_dialog_established_hdlr: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_handle_generic_event: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_process_event: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_mid_dialog_container, cur_state:S_SIP_IWF_SDP_DONE, event:E_SIP_IWF_EV_CALL_ACTIVE Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/is_mode_sip_sip: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/is_mode_sip_h323: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/is_mode_sip_h32x: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/is_mode_sip_default: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_set_tdm_ip_call_active: Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_default_mid_dialog_container Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/ccsip_cnfsm_debugs: OA:next_state:CNFSM_NO_STATE_CHANGE Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sipSPIPushOrigRequestContainerIntoHolder: Request Container Holder is above threshold...trimming Mar 16 17:47:32.933: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddRouteHeaders: status = TRUE Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sipSPISendAck: Associated container=0x31CA35D8 to Ack Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x31CF35D0, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x2534B320 Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Mar 16 17:47:32.933: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:69.18.5.8, rport:5060 with laddr: Mar 16 17:47:32.933: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x31C52D70 is already on connection=0x31598EF4 context_list Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x31CF35D0 Mar 16 17:47:32.933: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x31CF35D0, addr=69.18.5.8, port=5060, local_addr=, connId=2 for UDP Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/State/sipSPIChangeState: 0x31C52D70 : State change from (STATE_SENT_MIDCALL_INVITE, SUBSTATE_NONE) to (STATE_ACTIVE, SUBSTATE_NONE) Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sipSPISendAckForMidCallInvite: Transaction Complete. Lock on Facilities released. Mar 16 17:47:32.933: //73/F227CBEB80ED/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled. Mar 16 17:47:32.937: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Sent: ACK sip:+17778889999@107.17.5.140:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK2B110 From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Date: Mon, 16 Mar 2020 17:47:32 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Max-Forwards: 70 CSeq: 103 ACK Allow-Events: telephone-event Content-Length: 0 Mar 16 17:47:34.597: //73/F227CBEB80ED/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:307C6E04 Mar 16 17:47:34.613: //73/F227CBEB80ED/SIP/Info/ccsip_call_statistics: Requesting stats for callid=73 Mar 16 17:47:34.613: //73/F227CBEB80ED/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 29 Mar 16 17:47:34.613: //73/F227CBEB80ED/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service Mar 16 17:47:34.613: //73/F227CBEB80ED/SIP/Info/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg.. Mar 16 17:47:34.613: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT Mar 16 17:47:34.617: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8 Mar 16 17:47:34.617: //73/F227CBEB80ED/SIP/Info/act_active_disconnect: Disconnect deferred, as stats request pending Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Info/ccsip_indicate_rt_packet_stats: Processing stats for callid=73, proc_id=1 Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 29 Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Info/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg.. Mar 16 17:47:34.821: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT Mar 16 17:47:34.821: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8 Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Info/sipSPIPushOrigRequestContainerIntoHolder: Request Container Holder is above threshold...trimming Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Mar 16 17:47:34.821: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddRouteHeaders: status = TRUE Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Info/sipSPISendBye: Associated container=0x31CA3B58 to Bye Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x31CF35D0, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x2534A8A4 Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Mar 16 17:47:34.821: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:69.18.5.8, rport:5060 with laddr: Mar 16 17:47:34.821: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x31C52D70 is already on connection=0x31598EF4 context_list Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x31CF35D0 Mar 16 17:47:34.821: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x31CF35D0, addr=69.18.5.8, port=5060, local_addr=, connId=2 for UDP Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/Info/sentByeDisconnecting: Sent Bye Request, starting DisconnectTimer Mar 16 17:47:34.821: //73/F227CBEB80ED/SIP/State/sipSPIChangeState: 0x31C52D70 : State change from (STATE_ACTIVE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE) Mar 16 17:47:34.825: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:+17778889999@107.17.5.140:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK2C3CA From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Date: Mon, 16 Mar 2020 17:47:32 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 User-Agent: Cisco-SIPGateway/IOS-15.2.1.T3 Max-Forwards: 70 Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Timestamp: 1584380854 CSeq: 104 BYE Reason: Q.850;cause=16 P-RTP-Stat: PS=737,OS=93125,PR=459,OR=73440,PL=0,JI=1,LA=0,DU=36 Content-Length: 0 Mar 16 17:47:35.593: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.18.5.8]:5060, local_address:[ - ] Mar 16 17:47:35.593: //73/F227CBEB80ED/SIP/Info/sipSPIStopHoldTimer: Stopping hold timer Mar 16 17:47:35.593: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddRouteHeaders: status = TRUE Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Mar 16 17:47:35.593: //73/F227CBEB80ED/SIP/Info/sipSPISendBye: Associated container=0x31CA3B58 to Bye Mar 16 17:47:35.593: //73/F227CBEB80ED/SIP/Transport/sipSPISendBye: Sending BYE to the transport layer Mar 16 17:47:35.593: //73/F227CBEB80ED/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE Mar 16 17:47:35.593: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: msg=0x31CF35D0, addr=69.18.5.8, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0 Mar 16 17:47:35.593: //73/F227CBEB80ED/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately Mar 16 17:47:35.593: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0 Mar 16 17:47:35.593: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:69.18.5.8, rport:5060 with laddr: Mar 16 17:47:35.593: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x31C52D70 is already on connection=0x31598EF4 context_list Mar 16 17:47:35.593: //73/F227CBEB80ED/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x31CF35D0 Mar 16 17:47:35.597: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x31CF35D0, addr=69.18.5.8, port=5060, local_addr=, connId=2 for UDP Mar 16 17:47:35.597: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Mar 16 17:47:35.597: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2BDDC50C Mar 16 17:47:35.597: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2BDDC50C, addr=69.18.5.8, port=5060, local_addr=, connid=2, transport=UDP Mar 16 17:47:35.597: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 2 Mar 16 17:47:35.597: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK2C3CA from via branch list Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Via: SIP/2.0/UDP 10.21.10.12:5060;rport=63967;received=107.211.204.153;branch=z9hG4bK2C3CA Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 CSeq: 104 BYE Record-Route: <sip:69.18.5.7:5060;lr> Record-Route: <sip:69.18.5.8:5060;lr> Content-Length: 0 Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/sipSPIIcpifUpdate: CallState: 3 Playout: 5290 DiscTime:15523801 ConnTime 15520117 Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Media/sipSPIDestroyRtpSession: stream:307C6E04 Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/State/sipSPIChangeState: 0x31C52D70 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE) Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Call/sipSPICallInfo: The Call Setup Information is: Call Control Block (CCB) : 0x31C52D70 State of The Call : STATE_DEAD TCP Sockets Used : NO Calling Number : 13334445555 Called Number : 12345*17778889999 Source IP Address (Sig ): 10.21.10.12 Destn SIP Req Addr:Port : 69.18.5.8:5060 Destn SIP Resp Addr:Port : 69.18.5.8:5060 Destination Name : sip.provider.com Mar 16 17:47:35.597: //73/F227CBEB80ED/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): 10.21.10.12 Source IP Port (Media): 28022 Destn IP Address (Media): 107.17.5.42 Destn IP Port (Media): 26864 Orig Destn IP Address:Port (Media): [ - ]:0 Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Call/sipSPICallInfo: Disconnect Cause (CC) : 16 Disconnect Cause (SIP) : 200 Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 49 Mar 16 17:47:35.597: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[47] removed. Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table. Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x31C52D70 key=F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/sipSPIStopRequestPendingTimer: Stopping Request Pending Timer Mar 16 17:47:35.597: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x2BDDC50C, addr=69.18.5.8, port=5060, local_addr=, unregistering context=0x31C52D70 Mar 16 17:47:35.597: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstancePurgeContextInConnection: Purging context gcb=0x31C52D70 from the connection=0x31598EF4 context list Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/ccsip_offer_ans_delete: Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/ccsip_iwf_delete: Mar 16 17:47:35.597: //73/F227CBEB80ED/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 31C52D70 Mar 16 17:47:35.597: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[47] Mar 16 17:47:35.601: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Sent: BYE sip:+17778889999@107.17.5.140:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.10.12:5060;branch=z9hG4bK2C3CA From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Date: Mon, 16 Mar 2020 17:47:32 GMT Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 User-Agent: Cisco-SIPGateway/IOS-15.2.1.T3 Max-Forwards: 70 Route: <sip:69.18.5.8:5060;lr>,<sip:69.18.5.7:5060;lr> Timestamp: 1584380855 CSeq: 104 BYE Reason: Q.850;cause=16 P-RTP-Stat: PS=737,OS=93125,PR=459,OR=73440,PL=0,JI=1,LA=0,DU=36 Content-Length: 0 Mar 16 17:47:35.969: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [69.18.5.8]:5060, local_address:[ - ] Mar 16 17:47:35.973: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 Mar 16 17:47:35.973: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x2BDDC50C Mar 16 17:47:35.973: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x2BDDC50C, addr=69.18.5.8, port=5060, local_addr=, connid=2, transport=UDP Mar 16 17:47:35.973: //-1/xxxxxxxxxxxx/SIP/Info/sipHolderGetConnInstance: Return existing connection for port 5060 connId 2 Mar 16 17:47:35.973: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog Mar 16 17:47:35.973: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK From: <sip:13334445555@10.21.10.12>;tag=94024FC-94F To: <sip:12345*17778889999@sip.provider.com>;tag=gK0aaa1ec4 Via: SIP/2.0/UDP 10.21.10.12:5060;rport=63967;received=107.211.204.153;branch=z9hG4bK2C3CA Call-ID: F688689C-66E411EA-80F2AE40-46C6A4E2@10.21.10.12 CSeq: 104 BYE Record-Route: <sip:69.18.5.7:5060;lr> Record-Route: <sip:69.18.5.8:5060;lr> Content-Length: 0 Mar 16 17:47:35.973: //-1/xxxxxxxxxxxx/SIP/Error/sipSPILocateInviteDialogCCB: Could not find ccb for response
... View more
Labels:
03-16-2020
10:46 AM
I need to add a 1 to dialed number if it does not contain one. I am using the rule below and what it does is it replaces the first digit with a 1 not append to it. EX: I dial 2223334444 I get 1223334444 (replacing the first 2 with a 1) How can I fix this? rule 2 /^[2-9]/ /1/ q
... View more
Labels:
03-16-2020
05:20 AM
Yes that is how my provider wants the number dialed. I see that it is working when I do the test, but when I call the number it does not get translated. The number I call gets forward without any translations to the provider. Is it not matching the correct dial-peer? I have a catchall inbound to my Pots lines then the outbound dial-peers, they are as follows: dial-peer voice 100 voip description CatchAll Incomming destination-pattern +1T progress_ind setup enable 3 session protocol sipv2 session transport udp dtmf-relay rtp-nte codec g711ulaw ip qos dscp cs5 media ip qos dscp cs4 signaling no vad ! dial-peer voice 201 pots destination-pattern 13052227925 port 1/0/0 ! dial-peer voice 101 voip description Service Number (911, 411, etc) destination-pattern [2-9]11 progress_ind setup enable 3 session protocol sipv2 session target ipv4:10.21.10.4 session transport udp ip qos dscp cs5 media ip qos dscp cs4 signaling no vad ! dial-peer voice 102 voip description 11 Digit dialing destination-pattern 1[2-9]......... progress_ind setup enable 3 session protocol sipv2 session target dns:sip.provider.com session transport udp dtmf-relay rtp-nte codec g711ulaw ip qos dscp cs5 media ip qos dscp cs4 signaling no vad ! dial-peer voice 103 voip description 10 Digit Dialing translation-profile outgoing ADD12345*1 destination-pattern [2-9]......... progress_ind setup enable 3 session protocol sipv2 session target dns:sip.provider.com session transport udp dtmf-relay rtp-nte codec g711ulaw ip qos dscp cs5 media ip qos dscp cs4 signaling no vad
... View more
03-15-2020
06:52 PM
I am new to dial-peers. I need to create a rule that would prepped my called number with the carrier's prefix. If the user dials a 1 I would like to keep it if not add the 1. So my call is user1 dials 2223334444 I need it to get translated to 12345*1222333444 before reaching the carrier, but also if user2 dials 15556667777 I need it to get translated to 12345*15556667777. Not sure If I need two translations or just one. The following is not working for me: dial-peer voice 103 voip description 10 Digit Dialing destination-pattern [2-9]......... progress_ind setup enable 3 codec g711ulaw session protocol sipv2 dtmf-relay rtp-nte session target dns:sip.provider.com translation-profile outgoing ADD612345*1 session transport udp ip qos dscp cs5 media ip qos dscp cs4 signaling no vad voice translation-rule 10 rule 1 // /12345*1/ voice translation-profile ADD12345*1 translate called 1
... View more
Labels:
03-11-2020
11:29 AM
I got a Cisco 2911 that I have installed an 8port Analog card on Slot1 and an 4 port FXO port card on EHWIC2. When I boot up the router I get the following error message. Not sure what to do from here. Can I add more memory to the router, or do something else? Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/2 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/3 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/4 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/5 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/6 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/7 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/8 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/9 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/10 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/11 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/12 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/13 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/14 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/15 Not initialized due to insufficient DSP resources Mar 11 17:34:03.703: %DSPRM-3-INSUFFICIENT_DSP: voice-port : 1/0/16 Not initialized due to insufficient DSP resources
... View more
Labels:
Created by
Joli Martinez
in IP Telephony and Phones
in IP Telephony and Phones
03-09-2020
06:36 PM
03-09-2020
06:36 PM
That worked great. The only issue now is that I am receiving the invite on the SBC as nobody@SBCIP I have enabled callerid on the voice-port and no change. Any suggestions?
... View more
Created by
Joli Martinez
in IP Telephony and Phones
in IP Telephony and Phones
03-09-2020
08:02 AM
03-09-2020
08:02 AM
Hello I have an IAD2430 with an FXO card on it. Customer has an analog line from the provider. I need to send all inbound calls from the provider to the IPPBX via SIP. I have the following config on the IAD, but when I call the phone number the number just rings and rings nothing happens. Call never reaches the IPPBX. When I debug the IAD the output is what I get, not sure how to read it. dial-peer voice 100 pots description +12223334444 incoming called-number +12223334444 direct-inward-dial port 0/0 ! dial-peer voice 200 voip destination-pattern .T session protocol sipv2 session target ipv4:10.41.100.2 session transport udp codec g711ulaw ip qos dscp cs5 media ip qos dscp cs4 signaling no vad *Mar 1 12:28:03.552: htsp_process_event: [0/0, FXOLS_ONHOOK, E_DSP_SIG_0000]fxols_onhook_ringing
*Mar 1 12:28:03.552: htsp_timer - 125 msec
*Mar 1 12:28:03.680: htsp_process_event: [0/0, FXOLS_WAIT_RING_MIN, E_HTSP_EVENT_TIMER]fxols_wait_ring_min_timer
*Mar 1 12:28:03.680: htsp_timer - 10000 msec
*Mar 1 12:28:05.776: htsp_process_event: [0/0, FXOLS_RINGING, E_DSP_SIG_0100]
*Mar 1 12:28:05.776: fxols_ringing_not
*Mar 1 12:28:05.776: htsp_timer_stop
*Mar 1 12:28:05.776: htsp_timer_stop3 htsp_setup_ind
*Mar 1 12:28:05.780: [0/0] get_local_station_id calling num= calling name= calling time=03/01 12:28 orig called=
*Mar 1 12:28:05.784: htsp_process_event: [0/0, FXOLS_WAIT_SETUP_ACK, E_HTSP_SETUP_ACK]
*Mar 1 12:28:05.784: fxols_wait_setup_ack:
*Mar 1 12:28:05.784: [0/0] set signal state = 0xC timestamp = 0fxols_check_auto_call
*Mar 1 12:28:05.796: htsp_process_event: [0/0, FXOLS_PROCEEDING, E_HTSP_PROCEEDING]fxols_offhook_proc
*Mar 1 12:28:05.796: htsp_timer - 120000 msec
*Mar 1 12:28:05.796: htsp_process_event: [0/0, FXOLS_PROCEEDING, E_HTSP_RELEASE_REQ]fxols_offhook_release
*Mar 1 12:28:05.796: htsp_timer_stop
*Mar 1 12:28:05.796: htsp_timer_stop2
*Mar 1 12:28:05.800: htsp_timer_stop3
*Mar 1 12:28:05.800: [0/0] set signal state = 0x4 timestamp = 0
*Mar 1 12:28:05.800: htsp_timer - 2000 msec
*Mar 1 12:28:06.068: htsp_process_event: [0/0, FXOLS_GUARD_OUT, E_DSP_SIG_0110]
*Mar 1 12:28:07.800: htsp_process_event: [0/0, FXOLS_GUARD_OUT, E_HTSP_EVENT_TIMER]fxols_guard_out_timeout
*Mar 1 12:28:07.800: htsp_process_event: [0/0, FXOLS_ONHOOK, E_DSP_SIG_0100]
... View more
Labels:
03-06-2020
03:09 PM
I just need to configure the incoming calls at the moment. I will create a SIP trunk to the provider for outbound calls. I have an Rj11 plugged into port 0/0/0 and when I dial the number the call rings once then I get a dial tone. I would like all calls inbound from the PSTN to go to my IPPBX. What am I missing? dial-peer voice 100 pots
destination-pattern .T
incoming called-number .T
port 0/0/0
!
dial-peer voice 101 voip
destination-pattern .T
session target ipv4:192.168.1.10
... View more
03-06-2020
11:18 AM
This is what I gather. For an inbound call PSTN PHONE -> Analog Line -> Router -> PBX -> PBX PHONE Where my IPPBX = 192.168.1.10 I am looking to send all inbound traffic to the IPPBX. Is this correct? !--- FXS port
voice-port 1/0/0
!
dial-peer voice 1 pots
destination-pattern .T
port 1/0/0
!
dial-peer voice 2 voip
destination-pattern .T
session target ipv4:192.168.1.10
DTMF-relay cisco-rtp
... View more
03-27-2020
I have an analog line coming in from the provider and I need to send it
to the IPPBX. I have gone ba...
03-26-2020
The carrier is delivering an analog port to an IAD. The IAD is supposed
to send it to an IPPBX. When...
03-26-2020
I have a Mac running Catalina and I am using jabber 12.8.0. I am able to
sign in with the same crede...
03-21-2020
I have an old 2400 series IAD. I am configuring this for SIP traffic. Is
there anything special I ne...
03-20-2020
I have a call from Freeswitch to an IAD going back to our SBC. The
dial-peer is matched but I am hav...
03-16-2020
I have created the following dial-peer. This is only used for outbound
faxing, inbound comes in via ...
03-16-2020
I need to add a 1 to dialed number if it does not contain one. I am
using the rule below and what it...
03-16-2020
Yes that is how my provider wants the number dialed. I see that it is
working when I do the test, bu...
03-15-2020
I am new to dial-peers. I need to create a rule that would prepped my
called number with the carrier...
03-11-2020
I got a Cisco 2911 that I have installed an 8port Analog card on Slot1
and an 4 port FXO port card o...
Created by
Joli Martinez
in IP Telephony and Phones
03-09-2020
03-09-2020
That worked great. The only issue now is that I am receiving the invite
on the SBC as nobody@SBCIPI ...
Created by
Joli Martinez
in IP Telephony and Phones
03-09-2020
03-09-2020
Hello I have an IAD2430 with an FXO card on it. Customer has an analog
line from the provider. I nee...
Public Statistics
| Date Registered | 08-27-2011 02:08 PM |
| Date Last Visited | 03-29-2020 09:37 AM |
| Total Messages Posted | 159 |
