Buy or Renew
Buy or Renew
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
cancel
Start a conversation
2031
Views
30
Helpful
9
Replies

No voice for inbound PSTN calls &also outbound PSTN calls gets disconn

mzee.sidd
Level 1
Level 1

‎10-05-2021 10:52 PM - edited ‎10-05-2021 11:23 PM

Customer has introduced firewall in the network and post this there is no voice for inbound PSTN calls & also outbound PSTN calls gets disconnected in a sec while dialing,and there is a SIP trunk between Cucm and VG . We have shared the ports details to be allowed in the firewall for resolving the issue but its the same behaviour though customer states they have allowed all traffic in the rule. What could be the issue here.

Here are the logs below:

009111: Oct 1 17:50:39.687: ISDN Se0/1/0:15 Q931: RX <- SETUP pd = 8 callref = 0x017A
Bearer Capability i = 0x8090A3
Standard = CCITT
Transfer Capability = Speech
Transfer Mode = Circuit
Transfer Rate = 64 kbit/s
Channel ID i = 0xA98381
Exclusive, Channel 1
Calling Party Number i = 0x1183, '919892336029'
Plan:ISDN, Type:International
Called Party Number i = 0xC1, '6623'
Plan:ISDN, Type:Subscriber(local)
Sending Complete
009112: Oct 1 17:50:39.691: ISDN Se0/1/0:15 Q931: Received SETUP callref = 0x817A callID = 0x3F2A switch = primary-net5 interface = User
009113: Oct 1 17:50:39.695: //-1/D2F2F7A4BF1F/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=919892336029
cisco-anitype=1
cisco-aniplan=1
cisco-anipi=0
cisco-anisi=3
dest=6623
cisco-desttype=4
cisco-destplan=1
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=-1
cisco-rdnplan=-1
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

009114: Oct 1 17:50:39.695: //-1/D2F2F7A4BF1F/CCAPI/cc_api_call_setup_ind_common:
Interface=0x23E1208C, Call Info(
Calling Number=919892336029,(Calling Name=)(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed),
Called Number=6623(TON=Subscriber, NPI=ISDN),
Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE,
Incoming Dial-peer=101, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1
009115: Oct 1 17:50:39.695: //-1/D2F2F7A4BF1F/CCAPI/ccCheckClipClir:
In: Calling Number=919892336029(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed)
009116: Oct 1 17:50:39.695: //-1/D2F2F7A4BF1F/CCAPI/ccCheckClipClir:
Out: Calling Number=919892336029(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed)
009117: Oct 1 17:50:39.695: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009118: Oct 1 17:50:39.695: :cc_get_feature_vsa malloc success
009119: Oct 1 17:50:39.695: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009120: Oct 1 17:50:39.695: cc_get_feature_vsa count is 1
009121: Oct 1 17:50:39.695: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009122: Oct 1 17:50:39.695: :FEATURE_VSA attributes are: feature_name:0,feature_time:975181800,feature_id:96686
009123: Oct 1 17:50:39.695: //8771628/D2F2F7A4BF1F/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=919892336029(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed),
Called Number=6623(TON=Subscriber, NPI=ISDN))
009124: Oct 1 17:50:39.695: //8771628/D2F2F7A4BF1F/CCAPI/cc_process_call_setup_ind:
Event=0x23A1B2E0
009125: Oct 1 17:50:39.695: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 6623
009126: Oct 1 17:50:39.695: //8771628/D2F2F7A4BF1F/CCAPI/ccCallSetContext:
Context=0x3FB4E9BC
009127: Oct 1 17:50:39.695: //8771628/D2F2F7A4BF1F/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 8771628 with tag 101 to app "_ManagedAppProcess_Default"
009128: Oct 1 17:50:39.695: //8771628/D2F2F7A4BF1F/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
009129: Oct 1 17:50:39.699: //8771628/D2F2F7A4BF1F/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=100, Params=0x240E4A44, Progress Indication=NULL(0)
009130: Oct 1 17:50:39.699: //8771628/D2F2F7A4BF1F/CCAPI/ccCheckClipClir:
In: Calling Number=919892336029(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed)
009131: Oct 1 17:50:39.699: //8771628/D2F2F7A4BF1F/CCAPI/ccCheckClipClir:
Out: Calling Number=919892336029(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed)
009132: Oct 1 17:50:39.699: //8771628/D2F2F7A4BF1F/CCAPI/ccCallSetupRequest:
Destination Pattern=6..., Called Number=6623, Digit Strip=FALSE
009133: Oct 1 17:50:39.699: //8771628/D2F2F7A4BF1F/CCAPI/ccCallSetupRequest:
Calling Number=919892336029(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed),
Called Number=6623(TON=Subscriber, NPI=ISDN),
Redirect Number=, Display Info=
Account Number=, Final Destination Flag=TRUE,
Guid=D2F2F7A4-21E8-11EC-BF1F-FC5B39C3C360, Outgoing Dial-peer=100
009134: Oct 1 17:50:39.699: //8771628/D2F2F7A4BF1F/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=919892336029
cisco-anitype=1
cisco-aniplan=1
cisco-anipi=0
cisco-anisi=3
dest=6623
cisco-desttype=4
cisco-destplan=1
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=-1
cisco-rdnplan=-1
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

009135: Oct 1 17:50:39.699: //8771628/D2F2F7A4BF1F/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x3EB6E258, Interface Type=3, Destination=, Mode=0x0,
Call Params(Calling Number=919892336029,(Calling Name=)(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed),
Called Number=6623(TON=Subscriber, NPI=ISDN), Calling Translated=FALSE,
Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=100, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
009136: Oct 1 17:50:39.699: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009137: Oct 1 17:50:39.699: :cc_get_feature_vsa malloc success
009138: Oct 1 17:50:39.699: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009139: Oct 1 17:50:39.699: cc_get_feature_vsa count is 2
009140: Oct 1 17:50:39.699: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009141: Oct 1 17:50:39.699: :FEATURE_VSA attributes are: feature_name:0,feature_time:975191208,feature_id:96687
009142: Oct 1 17:50:39.699: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x23D39A50) with key=[8740260] to table
009143: Oct 1 17:50:39.699: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init:
009144: Oct 1 17:50:39.699: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init:
009145: Oct 1 17:50:39.699: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised..
009146: Oct 1 17:50:39.699: //8771629/000000000000/SIP/State/sipSPIChangeState: 0x23D39A50 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
009147: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/critical/32768/ccsip_ipip_media_forking_read_from_TDContainer: MF: Unable to read data from TD Container..
009148: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/critical/32768/ccsip_ipip_media_forking_forked_leg_config: MF: TD container cannot be read/container is NULL. Setting of forked call leg failed..
009149: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 1, Event Id: EV_UNDEFINED
009150: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: IWF Event: E_SIP_IWF_EV_SET_MODE
009151: Oct 1 17:50:39.699: //8771629/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SET_MODE
009152: Oct 1 17:50:39.699: //8771629/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container
009153: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009154: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_mode_sip_sip_md_snr:
009155: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009156: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_mode_sip_sip_ed_snr:
009157: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009158: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_mode_sip_sip_md:
009159: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009160: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_mode_sip_sip_ed:
009161: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009162: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_mode_sip_h32x_in_set_mode:
009163: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009164: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_mode_sip_h323_in_set_mode:
009165: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009166: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_mode_sip_sccp_in_set_mode:
009167: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009168: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_mode_sip_sccp_in_set_mode:
009169: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/8192/sip_iwf_def_set_mode_hdlr: Setting SPI mode to SIP-TDM
009170: Oct 1 17:50:39.699: //8771629/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_default_early_dialog_container
009171: Oct 1 17:50:39.699: //8771629/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE
009172: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_iwf_handle_peer_event: Return value: SIP_IWF_SUCCESS
009173: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: CC_EV_IF_DIAG_DONE
009174: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: IWF Event: E_SIP_IWF_EV_SET_FLOW_MODE
009175: Oct 1 17:50:39.699: //8771629/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SET_FLOW_MODE
009176: Oct 1 17:50:39.699: //8771629/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container
009177: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_fa2ft_md_flow_mode_transition:
009178: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_fa2ft_flow_mode_transition:
009179: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_get_flow_mode_frm_set_flow_mode_ev:
009180: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/is_fa2ft_flow_mode_transition:
009181: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/info/4096/ccsip_get_flow_mode_frm_set_flow_mode_ev:
009182: Oct 1 17:50:39.699: //8771629/000000000000/SIP/Info/verbose/4096/ccsip_iwf_process_event: IWF - cnfsm ret 2
009183: Oct 1 17:50:39.703: //8771629/000000000000/SIP/Info/info/4096/ccsip_iwf_handle_peer_event: Return value: SIP_IWF_SUCCESS
009184: Oct 1 17:50:39.703: //8771629/000000000000/SIP/Info/info/4096/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ipip = 200
009185: Oct 1 17:50:39.703: //8771629/000000000000/SIP/Info/info/4096/ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipip = 200
009186: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009187: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Error/sipSPIGetCallServerGroupTargets:
No server group configured
009188: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/5120/ccsip_call_setup_request: No dest server group configured
009189: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/verbose/5120/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : 132.149.98.11 target_port : 5060

009190: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/4096/sipSPIUaddccCallIdToTable: Adding call id 85D82D to table
009191: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/notify/131072/ccsip_call_setup_request: Incrementing call counter to [1] in dial-peer [100]
009192: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP
009193: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=3, FlowMode=2
009194: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/CCAPI/ccCallSetContext:
Context=0x240E49F4
009195: Oct 1 17:50:39.703: //8771628/D2F2F7A4BF1F/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=100
009196: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 2
009197: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/2049/sipSPIGetCallConfig: preferred_codec set[0] type :No Codec bytes: 0
009198: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/2048/sipSPI_ipip_store_config_info: Setting mid_call_config_info = 0x0 for callid = 8771629
009199: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/sipSPIGetCallConfig: Media forking disabled
009200: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/32768/sipSPIGetCallConfig: Media Antitrombone disabled
009201: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/notify/131072/sipSPICanSetFallbackFlag: Local Fallback is not active
009202: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/sipSPIGetCallConfig: VRF id = 0
009203: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-AROUND
009204: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/notify/8192/sipSPISetMediaFlowMode: Force the flow mode to FLOW-THROUGH for TDM-IP call and reset HD
009205: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder high-density disabled
009206: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
009207: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/4/update_video_params_from_config: Checking Video Type Rate=-1 video_codec_allowed=1F
009208: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
009209: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/12288/sipSPIGetModemInfoPerCall: peer_callID=8771628
009210: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/critical/32768/ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg..
009211: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/8704/sipSPIGetCallConfig: Incoming: No defer BYE for last
call stats
009212: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp configure for this leg.
009213: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/sipSPIGetCallConfig: Media forking disabled
009214: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: en_p->encap_s.voIP.voipPeerCfgMediaClass = 0
009215: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer has no media class recorder.
009216: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state = 0 & New state = -1
009217: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/32768/ccsip_ipip_media_forking_anchor_leg_reset: MF: Anchor leg config reset done...
009218: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/32768/ccsip_ipip_media_forking_intra_frame_request_config: MF: FIR en_p->encap_s.voIP.voipPeerCfgMediaClass = 0
009219: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/32768/ccsip_ipip_media_forking_get_forked_leg_config: MF: This leg is not forked call leg.
009220: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/critical/11264/ccsipInitDSCPPolicyInfo: No DSCP Profile configured, No RPH 2 DSCP Mapping and DSCP policing
009221: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/8192/sipSPIGetCallConfig: Initilise the DSCP policy
009222: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/8192/sipSPICheckFAAnatAssymetricOrDO2EO: Not a SIP-SIP call or not in FA mode
009223: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/notify/8192/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
009224: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/10240/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
009225: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/2048/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
009226: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009227: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/notify/10240/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
009228: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/5120/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host
009229: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/1/preprocessSetup:
This is a not a SIGO Call -, could be DM call
009230: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_INIT_CALL_SETUP
009231: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container
009232: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/4096/ccsip_iwf_process_event: IWF - cnfsm ret 2
009233: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/notify/4096/preprocessSetup: SIP-TDM or TCL/VXML app case
009234: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1
009235: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: peer_tag=100
009236: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_media_ip_address_to_bind: VRF id = 0
009237: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.30.20.42 for SIP
009238: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.30.20.42 for SIP
009239: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.30.20.42
009240: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/critical/1/sipSPIOutgoingCallSDP: Failure in creating outbound streams
SIP: (8771629) Group (a= group line) attribute, level 65535 instance 1 not found.
009241: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0
009242: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.30.20.42 for SIP
009243: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.30.20.42 for SIP
009244: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.30.20.42
009245: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.30.20.42
009246: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 32540 for stream 1
009247: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/1/sipSPIDoBearerCapToCodecMapping: Bearer capability to Codec Mapping: DISABLED

009248: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPIAddSDPMediaPayload: Preferred method of dtmf relay is: 6, with payload: 101
009249: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: calculating max bw from preffered codecs (local offer)
SIP: (8771629) Group (a= group line) attribute, level 65535 instance 1 not found.
009250: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: max bw (excluding pak overhead) from preffered codecs: codec g711ulaw bw 64000 index 0
009251: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/critical/2/sipSPIBwCacCalcMaxAudioBandwidth: audio caps channel idx not found !!!!
009252: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
009253: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: max bw (including pak overhead) from preffered codecs: codec g711ulaw bw 80000
009254: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
009255: Oct 1 17:50:39.703: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
009256: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/notify/8193/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
009257: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/info/1/sipSPIOutgoingCallSDP: Creating recv-only stream for outbound call
009258: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPIProcessRtpSessions: Processing stream state = STREAM_IDLE
009259: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPIProcessRtpSessions: No active streams.
009260: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/notify/4096/sip_gw_pre_setup_update_stream_media_direction: peer_callID = 8771628
009261: Oct 1 17:50:39.703: //8771629/D2F2F7A4BF1F/SIP/Info/critical/4097/sip_gw_pre_setup_update_stream_media_direction: peer_channels/stream is NULL
009262: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/1/sip_gw_pre_setup_add_sdp_container: SDP container added
009263: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted BW Option 0 flow mode flow-through
audio bw 80000 bps video bw 0 bps fax bw 0 bps total bw 80000 bps accounted bw 0 bps
009264: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/131072/sipSPIBwCacUpdateInterfaceBw: bwcac acquiring interface GigabitEthernet0/0 bw 80
009265: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted bw (initial offer) accounted bw set to 80000
009266: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/133120/sipSPIBwCacIsDialPeerBwAvailable: bwcac NOP dial-peer bw available tag 100
009267: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/notify/1/sipSPIBwCacIsInterfaceBwAvailable: bwcac interface bw threshold not configured
009268: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/131072/sipSPIBwCacVerifyBwThreshold: bwcac verify bw threshold, bw available allow call total bw 80000 bps
009269: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/critical/8192/sipSPIValidateGtd: Signal Forward disabled
009270: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/critical/8192/sipSPIValidateTunnelData: RawMsg/QSIG Tunneling Not Enabled
009271: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/critical/10240/sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg
009272: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/3072/sipSPIPreprocessUriFormat: Url cfg for 1: 2,phone-ctxt=FALSE
009273: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/9216/sipSPIAddCiscoGcid: Gcid value not set - not adding header.
009274: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/8192/sipSPIAddPrivacyandIdentityInfo: Removing "id" value from Privacy
009275: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/critical/2048/sipSPICompareHistoryInfoWithMatchedDialpeer: call-route history-info CLI not enabled
009276: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/critical/1024/sipSPI_ipip_set_history_info_header: No HI header recvd from container
009277: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0
009278: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.30.20.42 for SIP
009279: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.30.20.42 for SIP
009280: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.30.20.42
009281: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.30.20.42
009282: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/131072/sipSPIRscmsmAvail: Value returned by check is = 0
009283: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0
009284: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.30.20.42 for SIP
009285: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.30.20.42 for SIP
009286: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.30.20.42
009287: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.30.20.42
009288: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x23D39A50 D2F568DD-21E811EC-868A9D61-D45772BD@10.30.20.42
009289: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x23D39A50 key=D2F568DD-21E811EC-868A9D61-D45772BD@10.30.20.42 balance 1
009290: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/12288/sipSPIUsetBillingProfile: sipCallId for billing records = D2F568DD-21E811EC-868A9D61-D45772BD@10.30.20.42
009291: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/CCAPI/cc_api_call_proceeding:
Interface=0x3EB6E258, Progress Indication=NULL(0)
009292: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 132.149.98.11,Port 5060, Transport 1, SentBy Port 5060vrfid 0
009293: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone IST to SIP default timezone = GMT
009294: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3E132294 with refCount = 1
009295: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ
009296: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:0, container:2416538C
009297: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/Session-Timer/sipSTSLSRReqSend: Session timer is not required
009298: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
009299: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 0 event
009300: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
009301: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
009302: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/ccsip_offer_ans_handle_sent_sdp:
009303: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_IDLE, event:E_SIP_INVITE_SDP_SENT
009304: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/ccsip_offer_ans_is_invite_offer_valid: TRUE
009305: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/ccsip_offer_ans_common_offer_sent_hdlr:
009306: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/ccsip_iwf_handle_network_event:
009307: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SENT_SDP
009308: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/sip_iwf_def_ed_sent_sdp_offer_hdlr:
009309: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP
009310: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_SENT
009311: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Info/critical/2048/sipSPIgetRegistrarHost: registrar is not configured
009312: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg..
009313: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added.
009314: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Event/sipSPICreateRpid: Received Octet3A=0x83 -> Setting ;screen=yes ;privacy=off
SIP: (8771629) Group (a= group line) attribute, level 65535 instance 1 not found.
009315: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009316: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2416538C to Invite
009317: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 243
009318: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009319: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009320: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: msg=0x3E132294, addr=132.149.98.11, port=5060, sentBy_port=0, local_addr=10.30.20.42, is_req=1, transport=1, switch=0, callBack=0x359A16A8
009321: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009322: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009323: Oct 1 17:50:39.707: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009324: Oct 1 17:50:39.707: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x210DBC38,addr=132.149.98.11
009325: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnHolder: Created new holder=0x210DBC38, addr=132.149.98.11; nailed=FALSE
009326: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostRequestConnection: Posting UDP conn create request for addr=132.149.98.11, port=5060, context=0x222637E8
009327: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer: Wait timer set for connection=0x222642D8,addr=132.149.98.11, port=5060
009328: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer:
Wait Conn Timer started for 5000 msec
009329: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnInstance: Created new initiated conn=0x222642D8, connid=-1, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, transport=UDP
009330: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:132.149.98.11, rport:5060 with laddr:10.30.20.42

009331: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x23D39A50 with connection=0x222642D8
009332: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x23D39A50 with connection=0x222642D8
009333: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: Deferred sending msg=0x3E132294
009334: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Info/info/2/sipSPIUpdateCallEntry:
Call 8771629 set InfoType to SPEECH
009335: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 57
009336: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWConnectionCreated: context=0x222637E8
009337: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessConnCreated: gConnTab=0x222637E8, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connid=3, transport=UDP
009338: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessConnCreated: connection instance created for addr:132.149.98.11, port:5060 local_addr=10.30.20.42 local_port=52628

009339: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopConnWaitTimer: Wait timer stopped for connection=0x222642D8,addr=132.149.98.11, port=5060
009340: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnectionCreated: Moving connection=0x222642D8, connid=3 state to established. local_addr=10.30.20.42, local_port=52628
009341: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Transport/sipTransportPostInternalMsg: Posting Internal Msg type=0
009342: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 62
009343: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3E132294, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connId=3 vrfid=0 for UDP
009344: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Info/info/512/sentInviteRequest: Sent Invite in state STATE_IDLE
009345: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sentInviteRequest: Transaction active. Facilities will be queued.
009346: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/State/sipSPIChangeState: 0x23D39A50 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE)
009347: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPIProcessRtpSessions: Processing stream state = STREAM_ADDING
009348: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/6/sipSPIAddStream: set stream_callid from ccb->ccCallID:0x85D82D, media_type:0
009349: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 8771629) to the VOIP RTP library
009350: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1
009351: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
009352: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.30.20.42
009353: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
009354: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Info/info/1/sipSPIAssignStreamCallId: Assigning streamid 8771629 to stream 1. Old streamid = 8771629
009355: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/sipSPIUpdateRtcpSession: ccb->flags != LOOPBACK
009356: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPIUpdateRtcpSession: Setting do_rtcp = FALSE 0
009357: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
laddr = 10.30.20.42, lport = 32540, raddr = 0.0.0.0, rport=0, do_rtcp=FALSE
src_callid = 8771629, dest_callid = -1, stream type = voice+dtmf, stream direction = SENDRECV
media_ip_addr = - , vrf tableid = 0 media_addr_type = 1 negotiated_bandwidth (kbps) = 0 srtp_services = 0 nat_flag = 0
009358: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
009359: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/1/sipSPICreateRtpSession: sess: 21CBD868 do_rtcp:0
009360: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Media/sipSPICreateRtpSession: stun is disabled
009361: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Info/critical/131072/sipSPIUpdateRtcpSession: Not able to Associate DSCP Profile with GCCB dscp_policy = 0x0, IS_SIPSPI_MODE_IN_SIP_SIP = 0 dscpPolicySeviceBlock = 0x0 , stream->qos_info = 0x0
009362: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: Voice quality monitoring is not enabled for this RTP session due to sdp passthru enabled
009363: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: VQM: gccb=0x0, gccb->callId=0, ccb->ccCallID=8771629
009364: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Info/notify/2080/sipSPIUpdateRtcpSession: DTMF inb/oob disabled
009365: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/State/sipSPIChangeStreamState: Stream (callid = 8771629) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
009366: Oct 1 17:50:39.711: //8771629/D2F2F7A4BF1F/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:6623@132.149.98.11:5060 SIP/2.0
Via: SIP/2.0/UDP 10.30.20.42:5060;branch=z9hG4bKEA42B3B
Remote-Party-ID: <sip:919892336029@10.30.20.42>;party=calling;screen=yes;privacy=off
From: <sip:919892336029@10.30.20.42>;tag=7D0936B8-289
To: <sip:6623@132.149.98.11>
Date: Fri, 01 Oct 2021 17:50:39 GMT
Call-ID: D2F568DD-21E811EC-868A9D61-D45772BD@10.30.20.42
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 3539138468-0568857068-3206544475-0969130848
User-Agent: Cisco-SIPGateway/IOS-15.4.3.M8
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70

Timestamp: 1633090839
Contact: <sip:919892336029@10.30.20.42:5060>
Call-Info: <sip:10.30.20.42:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 243

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

009367: Oct 1 17:50:39.711: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3E132294
009368: Oct 1 17:50:39.711: ISDN Se0/1/0:15 Q931: TX -> CALL_PROC pd = 8 callref = 0x817A
Channel ID i = 0xA98381
Exclusive, Channel 1
009369: Oct 1 17:50:40.211: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone IST to SIP default timezone = GMT
009370: Oct 1 17:50:40.211: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3E132294 with refCount = 1
009371: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg..
009372: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added.
009373: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Event/sipSPICreateRpid: Received Octet3A=0x83 -> Setting ;screen=yes ;privacy=off
SIP: (8771629) Group (a= group line) attribute, level 65535 instance 1 not found.
009374: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009375: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2416538C to Invite
009376: Oct 1 17:50:40.211: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 243
009377: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009378: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009379: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: msg=0x3E132294, addr=132.149.98.11, port=5060, sentBy_port=0, local_addr=10.30.20.42, is_req=1, transport=1, switch=0, callBack=0x0
009380: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009381: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009382: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009383: Oct 1 17:50:40.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:132.149.98.11, rport:5060 with laddr:10.30.20.42

009384: Oct 1 17:50:40.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x23D39A50 is already on connection=0x222642D8 context_list
009385: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x3E132294
009386: Oct 1 17:50:40.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3E132294, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connId=3 vrfid=0 for UDP
009387: Oct 1 17:50:40.211: //8771629/D2F2F7A4BF1F/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:6623@132.149.98.11:5060 SIP/2.0
Via: SIP/2.0/UDP 10.30.20.42:5060;branch=z9hG4bKEA42B3B
Remote-Party-ID: <sip:919892336029@10.30.20.42>;party=calling;screen=yes;privacy=off
From: <sip:919892336029@10.30.20.42>;tag=7D0936B8-289
To: <sip:6623@132.149.98.11>
Date: Fri, 01 Oct 2021 17:50:40 GMT
Call-ID: D2F568DD-21E811EC-868A9D61-D45772BD@10.30.20.42
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 3539138468-0568857068-3206544475-0969130848
User-Agent: Cisco-SIPGateway/IOS-15.4.3.M8
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1633090840
Contact: <sip:919892336029@10.30.20.42:5060>
Call-Info: <sip:10.30.20.42:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180

Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 243

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

009388: Oct 1 17:50:40.211: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3E132294
009389: Oct 1 17:50:41.211: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone IST to SIP default timezone = GMT
009390: Oct 1 17:50:41.211: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3E132294 with refCount = 1
009391: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg..
009392: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added.
009393: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Event/sipSPICreateRpid: Received Octet3A=0x83 -> Setting ;screen=yes ;privacy=off
SIP: (8771629) Group (a= group line) attribute, level 65535 instance 1 not found.
009394: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009395: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2416538C to Invite
009396: Oct 1 17:50:41.211: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 243
009397: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009398: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009399: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: msg=0x3E132294, addr=132.149.98.11, port=5060, sentBy_port=0, local_addr=10.30.20.42, is_req=1, transport=1, switch=0, callBack=0x0
009400: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009401: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009402: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009403: Oct 1 17:50:41.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:132.149.98.11, rport:5060 with laddr:10.30.20.42

009404: Oct 1 17:50:41.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x23D39A50 is already on connection=0x222642D8 context_list
009405: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x3E132294
009406: Oct 1 17:50:41.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3E132294, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connId=3 vrfid=0 for UDP
009407: Oct 1 17:50:41.211: //8771629/D2F2F7A4BF1F/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:6623@132.149.98.11:5060 SIP/2.0
Via: SIP/2.0/UDP 10.30.20.42:5060;branch=z9hG4bKEA42B3B
Remote-Party-ID: <sip:919892336029@10.30.20.42>;party=calling;screen=yes;privacy=off
From: <sip:919892336029@10.30.20.42>;tag=7D0936B8-289
To: <sip:6623@132.149.98.11>

Date: Fri, 01 Oct 2021 17:50:41 GMT
Call-ID: D2F568DD-21E811EC-868A9D61-D45772BD@10.30.20.42
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 3539138468-0568857068-3206544475-0969130848
User-Agent: Cisco-SIPGateway/IOS-15.4.3.M8
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1633090841
Contact: <sip:919892336029@10.30.20.42:5060>
Call-Info: <sip:10.30.20.42:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 243

v=0
o=CiscoSystemsSIP-GW-UserAgent 789 2096 IN IP4 10.30.20.42

s=SIP Call
c=IN IP4 10.30.20.42
t=0 0
m=audio 32540 RTP/AVP 0 101
c=IN IP4 10.30.20.42
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

009408: Oct 1 17:50:41.211: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3E132294
009409: Oct 1 17:50:43.211: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone IST to SIP default timezone = GMT
009410: Oct 1 17:50:43.211: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3E132294 with refCount = 1
009411: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg..
009412: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added.
009413: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Event/sipSPICreateRpid: Received Octet3A=0x83 -> Setting ;screen=yes ;privacy=off
SIP: (8771629) Group (a= group line) attribute, level 65535 instance 1 not found.
009414: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009415: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2416538C to Invite
009416: Oct 1 17:50:43.211: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 243
009417: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009418: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009419: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: msg=0x3E132294, addr=132.149.98.11, port=5060, sentBy_port=0, local_addr=10.30.20.42, is_req=1, transport=1, switch=0, callBack=0x0
009420: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009421: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009422: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009423: Oct 1 17:50:43.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:132.149.98.11, rport:5060 with laddr:10.30.20.42

009424: Oct 1 17:50:43.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x23D39A50 is already on connection=0x222642D8 context_list
009425: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x3E132294
009426: Oct 1 17:50:43.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3E132294, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connId=3 vrfid=0 for UDP
009427: Oct 1 17:50:43.211: //8771629/D2F2F7A4BF1F/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:6623@132.149.98.11:5060 SIP/2.0
Via: SIP/2.0/UDP 10.30.20.42:5060;branch=z9hG4bKEA42B3B
Remote-Party-ID: <sip:919892336029@10.30.20.42>;party=calling;screen=yes;privacy=off
From: <sip:919892336029@10.30.20.42>;tag=7D0936B8-289
To: <sip:6623@132.149.98.11>
Date: Fri, 01 Oct 2021 17:50:43 GMT
Call-ID: D2F568DD-21E811EC-868A9D61-D45772BD@10.30.20.42
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 3539138468-0568857068-3206544475-0969130848
User-Agent: Cisco-SIPGateway/IOS-15.4.3.M8
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER

CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1633090843
Contact: <sip:919892336029@10.30.20.42:5060>
Call-Info: <sip:10.30.20.42:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 243

v=0
o=CiscoSystemsSIP-GW-UserAgent 789 2096 IN IP4 10.30.20.42
s=SIP Call
c=IN IP4 10.30.20.42
t=0 0
m=audio 32540 RTP/AVP 0 101
c=IN IP4 10.30.20.42
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

a=ptime:20

009428: Oct 1 17:50:43.211: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3E132294
009429: Oct 1 17:50:47.211: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone IST to SIP default timezone = GMT
009430: Oct 1 17:50:47.211: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3E132294 with refCount = 1
009431: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg..
009432: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added.
009433: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Event/sipSPICreateRpid: Received Octet3A=0x83 -> Setting ;screen=yes ;privacy=off
SIP: (8771629) Group (a= group line) attribute, level 65535 instance 1 not found.
009434: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009435: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2416538C to Invite
009436: Oct 1 17:50:47.211: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 243
009437: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009438: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009439: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: msg=0x3E132294, addr=132.149.98.11, port=5060, sentBy_port=0, local_addr=10.30.20.42, is_req=1, transport=1, switch=0, callBack=0x0
009440: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009441: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009442: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009443: Oct 1 17:50:47.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:132.149.98.11, rport:5060 with laddr:10.30.20.42

009444: Oct 1 17:50:47.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x23D39A50 is already on connection=0x222642D8 context_list
009445: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x3E132294
009446: Oct 1 17:50:47.211: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3E132294, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connId=3 vrfid=0 for UDP
009447: Oct 1 17:50:47.211: //8771629/D2F2F7A4BF1F/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:6623@132.149.98.11:5060 SIP/2.0
Via: SIP/2.0/UDP 10.30.20.42:5060;branch=z9hG4bKEA42B3B
Remote-Party-ID: <sip:919892336029@10.30.20.42>;party=calling;screen=yes;privacy=off
From: <sip:919892336029@10.30.20.42>;tag=7D0936B8-289
To: <sip:6623@132.149.98.11>
Date: Fri, 01 Oct 2021 17:50:47 GMT
Call-ID: D2F568DD-21E811EC-868A9D61-D45772BD@10.30.20.42
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 3539138468-0568857068-3206544475-0969130848
User-Agent: Cisco-SIPGateway/IOS-15.4.3.M8
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1633090847
Contact: <sip:919892336029@10.30.20.42:5060>
Call-Info: <sip:10.30.20.42:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180

Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 243

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

009448: Oct 1 17:50:47.211: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3E132294
009449: Oct 1 17:50:49.755: ISDN Se0/1/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0x017A
Cause i = 0x82E6 - Recovery on timer expiry
009450: Oct 1 17:50:49.755: ISDN Se0/1/0:15 Q931: TX -> RELEASE pd = 8 callref = 0x817A
009451: Oct 1 17:50:49.755: //8771628/D2F2F7A4BF1F/CCAPI/cc_api_call_disconnected:
Cause Value=102, Interface=0x23E1208C, Call Id=8771628
009452: Oct 1 17:50:49.755: //8771628/D2F2F7A4BF1F/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=FALSE, Cause Value=102, Retry Count=0)
009453: Oct 1 17:50:49.755: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/8192/ccsip_call_statistics: Requesting stats for callid=8771629
009454: Oct 1 17:50:49.755: //8771629/D2F2F7A4BF1F/SIP/Info/critical/8192/ccsip_call_statistics: Stats request failed for callid=8771629, dstCallID=-1, rc=-7
009455: Oct 1 17:50:49.755: //8771629/D2F2F7A4BF1F/CCAPI/ccCallDisconnect:
Cause Value=102, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
009456: Oct 1 17:50:49.755: //8771629/D2F2F7A4BF1F/CCAPI/ccCallDisconnect:
Cause Value=102, Call Entry(Responsed=FALSE, Cause Value=102)
009457: Oct 1 17:50:49.755: //8771629/D2F2F7A4BF1F/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 29
009458: Oct 1 17:50:49.755: //8771629/D2F2F7A4BF1F/SIP/Info/critical/32768/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg..
009459: Oct 1 17:50:49.755: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
009460: Oct 1 17:50:49.755: //8771628/D2F2F7A4BF1F/CCAPI/ccCallDisconnect:
Cause Value=102, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=102)
009461: Oct 1 17:50:49.759: //8771628/D2F2F7A4BF1F/CCAPI/ccCallDisconnect:
Cause Value=102, Call Entry(Responsed=TRUE, Cause Value=102)
009462: Oct 1 17:50:49.759: //8771628/D2F2F7A4BF1F/CCAPI/cc_api_get_transfer_info:
Transfer Number=NULL
009463: Oct 1 17:50:49.759: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8
009464: Oct 1 17:50:49.759: //8771629/D2F2F7A4BF1F/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SPI_EVENT
009465: Oct 1 17:50:49.759: //8771629/D2F2F7A4BF1F/SIP/Info/info/8192/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
009466: Oct 1 17:50:49.759: //8771629/D2F2F7A4BF1F/SIP/Info/critical/8192/sipSPIValidateGtd: Signal Forward disabled
009467: Oct 1 17:50:49.759: //8771629/D2F2F7A4BF1F/SIP/Info/critical/8192/sipSPIValidateTunnelData: RawMsg/QSIG Tunneling Not Enabled
009468: Oct 1 17:50:49.759: //8771629/D2F2F7A4BF1F/SIP/Info/info/133120/sipSPIBwCacReleaseDialPeerBw: bwcac dial-peer bw 80 Kbps released for tag 100 active bw 0 Kbps
009469: Oct 1 17:50:49.759: //8771629/D2F2F7A4BF1F/SIP/Info/info/131072/sipSPIBwCacReleaseInterfaceBw: bwcac releasing interface GigabitEthernet0/0 bw 80 Kbps
009470: Oct 1 17:50:49.759: //8771629/D2F2F7A4BF1F/SIP/Info/info/131072/sipSPIBwCacReleaseAccountedBw: bwcac released accounted bw 80000 bps
009471: Oct 1 17:50:49.759: //8771629/D2F2F7A4BF1F/SIP/Info/notify/4096/act_sentinvite_disconnect: Received POTS Disconnect - Holding CANCEL till we receive a response from remote end.
009472: Oct 1 17:50:49.759: //8771629/D2F2F7A4BF1F/SIP/Info/info/4096/act_sentinvite_disconnect: Using cancel pending instead of trying timer
009473: Oct 1 17:50:49.795: ISDN Se0/1/0:15 Q931: RX <- RELEASE_COMP pd = 8 callref = 0x017A
009474: Oct 1 17:50:49.795: //8771628/D2F2F7A4BF1F/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x23E1208C, Tag=0x0, Call Id=8771628,
Call Entry(Disconnect Cause=102, Voice Class Cause Code=0, Retry Count=0)
009475: Oct 1 17:50:49.799: //8771628/D2F2F7A4BF1F/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
009476: Oct 1 17:50:49.799: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

009477: Oct 1 17:50:49.799: :cc_free_feature_vsa freeing 3A2017E0
009478: Oct 1 17:50:49.799: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

009479: Oct 1 17:50:49.799: vsacount in free is 1
009480: Oct 1 17:51:07.627: ISDN Se0/1/0:15 Q931: RX <- SETUP pd = 8 callref = 0x017B
Bearer Capability i = 0x8090A3
Standard = CCITT
Transfer Capability = Speech
Transfer Mode = Circuit
Transfer Rate = 64 kbit/s
Channel ID i = 0xA98381
Exclusive, Channel 1
Calling Party Number i = 0x1183, '919967147467'
Plan:ISDN, Type:International
Called Party Number i = 0xC1, '6623'
Plan:ISDN, Type:Subscriber(local)
Sending Complete
009481: Oct 1 17:51:07.627: ISDN Se0/1/0:15 Q931: Received SETUP callref = 0x817B callID = 0x3F2B switch = primary-net5 interface = User
009482: Oct 1 17:51:07.635: //-1/E399B37DBF20/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=919967147467
cisco-anitype=1
cisco-aniplan=1
cisco-anipi=0
cisco-anisi=3
dest=6623
cisco-desttype=4
cisco-destplan=1
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=-1
cisco-rdnplan=-1
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

009483: Oct 1 17:51:07.635: //-1/E399B37DBF20/CCAPI/cc_api_call_setup_ind_common:
Interface=0x23E1208C, Call Info(
Calling Number=919967147467,(Calling Name=)(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed),
Called Number=6623(TON=Subscriber, NPI=ISDN),
Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE,
Incoming Dial-peer=101, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1
009484: Oct 1 17:51:07.635: //-1/E399B37DBF20/CCAPI/ccCheckClipClir:
In: Calling Number=919967147467(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed)
009485: Oct 1 17:51:07.635: //-1/E399B37DBF20/CCAPI/ccCheckClipClir:
Out: Calling Number=919967147467(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed)
009486: Oct 1 17:51:07.635: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009487: Oct 1 17:51:07.635: :cc_get_feature_vsa malloc success
009488: Oct 1 17:51:07.635: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009489: Oct 1 17:51:07.635: cc_get_feature_vsa count is 2
009490: Oct 1 17:51:07.635: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009491: Oct 1 17:51:07.635: :FEATURE_VSA attributes are: feature_name:0,feature_time:975181800,feature_id:96688
009492: Oct 1 17:51:07.635: //8771630/E399B37DBF20/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=919967147467(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed),
Called Number=6623(TON=Subscriber, NPI=ISDN))
009493: Oct 1 17:51:07.635: //8771630/E399B37DBF20/CCAPI/cc_process_call_setup_ind:
Event=0x23A1B2E0
009494: Oct 1 17:51:07.635: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 6623
009495: Oct 1 17:51:07.635: //8771630/E399B37DBF20/CCAPI/ccCallSetContext:
Context=0x2433EF08
009496: Oct 1 17:51:07.635: //8771630/E399B37DBF20/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 8771630 with tag 101 to app "_ManagedAppProcess_Default"
009497: Oct 1 17:51:07.635: //8771630/E399B37DBF20/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
009498: Oct 1 17:51:07.635: //8771630/E399B37DBF20/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=100, Params=0x3FB207D4, Progress Indication=NULL(0)
009499: Oct 1 17:51:07.635: //8771630/E399B37DBF20/CCAPI/ccCheckClipClir:
In: Calling Number=919967147467(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed)
009500: Oct 1 17:51:07.635: //8771630/E399B37DBF20/CCAPI/ccCheckClipClir:
Out: Calling Number=919967147467(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed)
009501: Oct 1 17:51:07.635: //8771630/E399B37DBF20/CCAPI/ccCallSetupRequest:
Destination Pattern=6..., Called Number=6623, Digit Strip=FALSE
009502: Oct 1 17:51:07.639: //8771630/E399B37DBF20/CCAPI/ccCallSetupRequest:
Calling Number=919967147467(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed),
Called Number=6623(TON=Subscriber, NPI=ISDN),
Redirect Number=, Display Info=
Account Number=, Final Destination Flag=TRUE,
Guid=E399B37D-21E8-11EC-BF20-FC5B39C3C360, Outgoing Dial-peer=100
009503: Oct 1 17:51:07.639: //8771630/E399B37DBF20/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=919967147467
cisco-anitype=1
cisco-aniplan=1
cisco-anipi=0
cisco-anisi=3
dest=6623
cisco-desttype=4
cisco-destplan=1
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=-1
cisco-rdnplan=-1
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

009504: Oct 1 17:51:07.639: //8771630/E399B37DBF20/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x3EB6E258, Interface Type=3, Destination=, Mode=0x0,
Call Params(Calling Number=919967147467,(Calling Name=)(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed),
Called Number=6623(TON=Subscriber, NPI=ISDN), Calling Translated=FALSE,
Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=100, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
009505: Oct 1 17:51:07.639: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009506: Oct 1 17:51:07.639: :cc_get_feature_vsa malloc success
009507: Oct 1 17:51:07.639: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009508: Oct 1 17:51:07.639: cc_get_feature_vsa count is 3
009509: Oct 1 17:51:07.639: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

009510: Oct 1 17:51:07.639: :FEATURE_VSA attributes are: feature_name:0,feature_time:975186056,feature_id:96689
009511: Oct 1 17:51:07.639: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x23D40108) with key=[8740261] to table
009512: Oct 1 17:51:07.639: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init:
009513: Oct 1 17:51:07.639: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init:
009514: Oct 1 17:51:07.639: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised..
009515: Oct 1 17:51:07.639: //8771631/000000000000/SIP/State/sipSPIChangeState: 0x23D40108 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
009516: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/critical/32768/ccsip_ipip_media_forking_read_from_TDContainer: MF: Unable to read data from TD Container..
009517: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/critical/32768/ccsip_ipip_media_forking_forked_leg_config: MF: TD container cannot be read/container is NULL. Setting of forked call leg failed..
009518: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 1, Event Id: EV_UNDEFINED
009519: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: IWF Event: E_SIP_IWF_EV_SET_MODE
009520: Oct 1 17:51:07.639: //8771631/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SET_MODE
009521: Oct 1 17:51:07.639: //8771631/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container
009522: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009523: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_mode_sip_sip_md_snr:
009524: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009525: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_mode_sip_sip_ed_snr:
009526: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009527: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_mode_sip_sip_md:
009528: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009529: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_mode_sip_sip_ed:
009530: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009531: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_mode_sip_h32x_in_set_mode:
009532: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009533: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_mode_sip_h323_in_set_mode:
009534: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009535: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_mode_sip_sccp_in_set_mode:
009536: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_get_int_type_frm_set_mode_ev:
009537: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_mode_sip_sccp_in_set_mode:
009538: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/8192/sip_iwf_def_set_mode_hdlr: Setting SPI mode to SIP-TDM
009539: Oct 1 17:51:07.639: //8771631/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_default_early_dialog_container
009540: Oct 1 17:51:07.639: //8771631/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE
009541: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_iwf_handle_peer_event: Return value: SIP_IWF_SUCCESS
009542: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: CC_EV_IF_DIAG_DONE
009543: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/verbose/4096/ccsip_iwf_map_ccapi_event_to_iwf_event: IWF Event: E_SIP_IWF_EV_SET_FLOW_MODE
009544: Oct 1 17:51:07.639: //8771631/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SET_FLOW_MODE
009545: Oct 1 17:51:07.639: //8771631/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container
009546: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_fa2ft_md_flow_mode_transition:
009547: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_fa2ft_flow_mode_transition:
009548: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_get_flow_mode_frm_set_flow_mode_ev:
009549: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/is_fa2ft_flow_mode_transition:
009550: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_get_flow_mode_frm_set_flow_mode_ev:
009551: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/verbose/4096/ccsip_iwf_process_event: IWF - cnfsm ret 2
009552: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_iwf_handle_peer_event: Return value: SIP_IWF_SUCCESS
009553: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ipip = 200
009554: Oct 1 17:51:07.639: //8771631/000000000000/SIP/Info/info/4096/ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipip = 200
009555: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009556: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Error/sipSPIGetCallServerGroupTargets:
No server group configured
009557: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/verbose/5120/ccsip_call_setup_request: No dest server group configured
009558: Oct 1 17:51:07.639: //-1/xxxxxxxxxxxx/SIP/Info/verbose/5120/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : 132.149.98.11 target_port : 5060

009559: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/verbose/4096/sipSPIUaddccCallIdToTable: Adding call id 85D82F to table
009560: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/notify/131072/ccsip_call_setup_request: Incrementing call counter to [2] in dial-peer [100]
009561: Oct 1 17:51:07.639: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP
009562: Oct 1 17:51:07.639: //8771631/E399B37DBF20/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=3, FlowMode=2
009563: Oct 1 17:51:07.639: //8771631/E399B37DBF20/CCAPI/ccCallSetContext:
Context=0x3FB20784
009564: Oct 1 17:51:07.639: //8771630/E399B37DBF20/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=100
009565: Oct 1 17:51:07.639: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 2
009566: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/info/2049/sipSPIGetCallConfig: preferred_codec set[0] type :No Codec bytes: 0
009567: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/verbose/2048/sipSPI_ipip_store_config_info: Setting mid_call_config_info = 0x0 for callid = 8771631
009568: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/info/8192/sipSPIGetCallConfig: Media forking disabled
009569: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/info/32768/sipSPIGetCallConfig: Media Antitrombone disabled
009570: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/notify/131072/sipSPICanSetFallbackFlag: Local Fallback is not active
009571: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/info/8192/sipSPIGetCallConfig: VRF id = 0
009572: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-AROUND
009573: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/notify/8192/sipSPISetMediaFlowMode: Force the flow mode to FLOW-THROUGH for TDM-IP call and reset HD
009574: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder high-density disabled
009575: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
009576: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Info/verbose/4/update_video_params_from_config: Checking Video Type Rate=-1 video_codec_allowed=1F
009577: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
009578: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/12288/sipSPIGetModemInfoPerCall: peer_callID=8771630
009579: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/critical/32768/ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg..
009580: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/8704/sipSPIGetCallConfig: Incoming: No defer BYE for last
call stats
009581: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp configure for this leg.
009582: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/8192/sipSPIGetCallConfig: Media forking disabled
009583: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: en_p->encap_s.voIP.voipPeerCfgMediaClass = 0
009584: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer has no media class recorder.
009585: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state = 0 & New state = -1
009586: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/32768/ccsip_ipip_media_forking_anchor_leg_reset: MF: Anchor leg config reset done...
009587: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/32768/ccsip_ipip_media_forking_intra_frame_request_config: MF: FIR en_p->encap_s.voIP.voipPeerCfgMediaClass = 0
009588: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/32768/ccsip_ipip_media_forking_get_forked_leg_config: MF: This leg is not forked call leg.
009589: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/critical/11264/ccsipInitDSCPPolicyInfo: No DSCP Profile configured, No RPH 2 DSCP Mapping and DSCP policing
009590: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/8192/sipSPIGetCallConfig: Initilise the DSCP policy
009591: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/8192/sipSPICheckFAAnatAssymetricOrDO2EO: Not a SIP-SIP call or not in FA mode
009592: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/notify/8192/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
009593: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/10240/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
009594: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/2048/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
009595: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009596: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/notify/10240/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
009597: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/5120/sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host
009598: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/1/preprocessSetup:
This is a not a SIGO Call -, could be DM call
009599: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_INIT_CALL_SETUP
009600: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container
009601: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/4096/ccsip_iwf_process_event: IWF - cnfsm ret 2
009602: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/notify/4096/preprocessSetup: SIP-TDM or TCL/VXML app case
009603: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1
009604: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: peer_tag=100
009605: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_media_ip_address_to_bind: VRF id = 0
009606: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.30.20.42 for SIP
009607: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.30.20.42 for SIP
009608: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.30.20.42
009609: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/critical/1/sipSPIOutgoingCallSDP: Failure in creating outbound streams
SIP: (8771631) Group (a= group line) attribute, level 65535 instance 1 not found.
009610: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0
009611: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.30.20.42 for SIP
009612: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.30.20.42 for SIP
009613: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.30.20.42
009614: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.30.20.42
009615: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 32608 for stream 1
009616: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/1/sipSPIDoBearerCapToCodecMapping: Bearer capability to Codec Mapping: DISABLED


009617: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Media/sipSPIAddSDPMediaPayload: Preferred method of dtmf relay is: 6, with payload: 101
009618: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: calculating max bw from preffered codecs (local offer)
SIP: (8771631) Group (a= group line) attribute, level 65535 instance 1 not found.
009619: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: max bw (excluding pak overhead) from preffered codecs: codec g711ulaw bw 64000 index 0
009620: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/critical/2/sipSPIBwCacCalcMaxAudioBandwidth: audio caps channel idx not found !!!!
009621: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
009622: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: max bw (including pak overhead) from preffered codecs: codec g711ulaw bw 80000
009623: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
009624: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
009625: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/notify/8193/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
009626: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/1/sipSPIOutgoingCallSDP: Creating recv-only stream for outbound call
009627: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Media/sipSPIProcessRtpSessions: Processing stream state = STREAM_IDLE
009628: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Media/sipSPIProcessRtpSessions: No active streams.
009629: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/notify/4096/sip_gw_pre_setup_update_stream_media_direction: peer_callID = 8771630
009630: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/critical/4097/sip_gw_pre_setup_update_stream_media_direction: peer_channels/stream is NULL
009631: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/1/sip_gw_pre_setup_add_sdp_container: SDP container added
009632: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted BW Option 0 flow mode flow-through
audio bw 80000 bps video bw 0 bps fax bw 0 bps total bw 80000 bps accounted bw 0 bps
009633: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/131072/sipSPIBwCacUpdateInterfaceBw: bwcac acquiring interface GigabitEthernet0/0 bw 80
009634: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/131072/sipSPIBwCacUpdateAccountedBw: bwcac update accounted bw (initial offer) accounted bw set to 80000
009635: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/133120/sipSPIBwCacIsDialPeerBwAvailable: bwcac NOP dial-peer bw available tag 100
009636: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/notify/1/sipSPIBwCacIsInterfaceBwAvailable: bwcac interface bw threshold not configured
009637: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/131072/sipSPIBwCacVerifyBwThreshold: bwcac verify bw threshold, bw available allow call total bw 80000 bps
009638: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/critical/8192/sipSPIValidateGtd: Signal Forward disabled
009639: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/critical/8192/sipSPIValidateTunnelData: RawMsg/QSIG Tunneling Not Enabled
009640: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/critical/10240/sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg
009641: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/3072/sipSPIPreprocessUriFormat: Url cfg for 1: 2,phone-ctxt=FALSE
009642: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/9216/sipSPIAddCiscoGcid: Gcid value not set - not adding header.
009643: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/verbose/8192/sipSPIAddPrivacyandIdentityInfo: Removing "id" value from Privacy
009644: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/critical/2048/sipSPICompareHistoryInfoWithMatchedDialpeer: call-route history-info CLI not enabled
009645: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/critical/1024/sipSPI_ipip_set_history_info_header: No HI header recvd from container
009646: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0
009647: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.30.20.42 for SIP
009648: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.30.20.42 for SIP
009649: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.30.20.42
009650: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.30.20.42
009651: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/131072/sipSPIRscmsmAvail: Value returned by check is = 0
009652: Oct 1 17:51:07.643: //8771631/E399B37DBF20/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0
009653: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.30.20.42 for SIP
009654: Oct 1 17:51:07.643: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.30.20.42 for SIP
009655: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.30.20.42
009656: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.30.20.42
009657: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x23D40108 E39CC0DD-21E811EC-86909D61-D45772BD@10.30.20.42
009658: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x23D40108 key=E39CC0DD-21E811EC-86909D61-D45772BD@10.30.20.42 balance 0
009659: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/verbose/12288/sipSPIUsetBillingProfile: sipCallId for billing records = E39CC0DD-21E811EC-86909D61-D45772BD@10.30.20.42
009660: Oct 1 17:51:07.647: //8771631/E399B37DBF20/CCAPI/cc_api_call_proceeding:
Interface=0x3EB6E258, Progress Indication=NULL(0)
009661: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 132.149.98.11,Port 5060, Transport 1, SentBy Port 5060vrfid 0
009662: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone IST to SIP default timezone = GMT
009663: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3FB345AC with refCount = 1
009664: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ
009665: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:0, container:2416C2EC
009666: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/8192/Session-Timer/sipSTSLSRReqSend: Session timer is not required
009667: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/8192/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
009668: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 0 event
009669: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
009670: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/notify/4096/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
009671: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/4096/ccsip_offer_ans_handle_sent_sdp:
009672: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_IDLE, event:E_SIP_INVITE_SDP_SENT
009673: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/4096/ccsip_offer_ans_is_invite_offer_valid: TRUE
009674: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/4096/ccsip_offer_ans_common_offer_sent_hdlr:
009675: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/4096/ccsip_iwf_handle_network_event:
009676: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SENT_SDP
009677: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/4096/sip_iwf_def_ed_sent_sdp_offer_hdlr:
009678: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP
009679: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_SENT
009680: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Info/critical/2048/sipSPIgetRegistrarHost: registrar is not configured
009681: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg..
009682: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added.
009683: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Event/sipSPICreateRpid: Received Octet3A=0x83 -> Setting ;screen=yes ;privacy=off
SIP: (8771631) Group (a= group line) attribute, level 65535 instance 1 not found.
009684: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009685: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2416C2EC to Invite
009686: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 244
009687: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009688: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009689: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Transport/sipSPITransportSendMessage: msg=0x3FB345AC, addr=132.149.98.11, port=5060, sentBy_port=0, local_addr=10.30.20.42, is_req=1, transport=1, switch=0, callBack=0x359A16A8
009690: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009691: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009692: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009693: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:132.149.98.11, rport:5060 with laddr:10.30.20.42

009694: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x23D40108 with connection=0x222642D8 context list
009695: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x3FB345AC
009696: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3FB345AC, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connId=3 vrfid=0 for UDP
009697: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/512/sentInviteRequest: Sent Invite in state STATE_IDLE
009698: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sentInviteRequest: Transaction active. Facilities will be queued.
009699: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/State/sipSPIChangeState: 0x23D40108 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE)
009700: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Media/sipSPIProcessRtpSessions: Processing stream state = STREAM_ADDING
009701: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/verbose/6/sipSPIAddStream: set stream_callid from ccb->ccCallID:0x85D82F, media_type:0
009702: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 8771631) to the VOIP RTP library
009703: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1
009704: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
009705: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.30.20.42
009706: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
009707: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/1/sipSPIAssignStreamCallId: Assigning streamid 8771631 to stream 1. Old streamid = 8771631
009708: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/8192/sipSPIUpdateRtcpSession: ccb->flags != LOOPBACK
009709: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Media/sipSPIUpdateRtcpSession: Setting do_rtcp = FALSE 0
009710: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
laddr = 10.30.20.42, lport = 32608, raddr = 0.0.0.0, rport=0, do_rtcp=FALSE
src_callid = 8771631, dest_callid = -1, stream type = voice+dtmf, stream direction = SENDRECV
media_ip_addr = - , vrf tableid = 0 media_addr_type = 1 negotiated_bandwidth (kbps) = 0 srtp_services = 0 nat_flag = 0
009711: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
009712: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/verbose/1/sipSPICreateRtpSession: sess: 3EF2D77C do_rtcp:0
009713: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Media/sipSPICreateRtpSession: stun is disabled
009714: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/critical/131072/sipSPIUpdateRtcpSession: Not able to Associate DSCP Profile with GCCB dscp_policy = 0x0, IS_SIPSPI_MODE_IN_SIP_SIP = 0 dscpPolicySeviceBlock = 0x0 , stream->qos_info = 0x0
009715: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: Voice quality monitoring is not enabled for this RTP session due to sdp passthru enabled
009716: Oct 1 17:51:07.647: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIUpdateRtcpSession: VQM: gccb=0x0, gccb->callId=0, ccb->ccCallID=8771631
009717: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/notify/2080/sipSPIUpdateRtcpSession: DTMF inb/oob disabled
009718: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/State/sipSPIChangeStreamState: Stream (callid = 8771631) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
009719: Oct 1 17:51:07.647: //8771631/E399B37DBF20/SIP/Info/info/2/sipSPIUpdateCallEntry:
Call 8771631 set InfoType to SPEECH
009720: Oct 1 17:51:07.651: //8771631/E399B37DBF20/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:6623@132.149.98.11:5060 SIP/2.0
Via: SIP/2.0/UDP 10.30.20.42:5060;branch=z9hG4bKEA4376A
Remote-Party-ID: <sip:919967147467@10.30.20.42>;party=calling;screen=yes;privacy=off
From: <sip:919967147467@10.30.20.42>;tag=7D09A3DC-F58
To: <sip:6623@132.149.98.11>
Date: Fri, 01 Oct 2021 17:51:07 GMT
Call-ID: E39CC0DD-21E811EC-86909D61-D45772BD@10.30.20.42
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 3818500989-0568857068-3206610011-0969130848
User-Agent: Cisco-SIPGateway/IOS-15.4.3.M8
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER

CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1633090867
Contact: <sip:919967147467@10.30.20.42:5060>
Call-Info: <sip:10.30.20.42:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 244

v=0
o=CiscoSystemsSIP-GW-UserAgent 5083 6944 IN IP4 10.30.20.42
s=SIP Call
c=IN IP4 10.30.20.42
t=0 0
m=audio 32608 RTP/AVP 0 101
c=IN IP4 10.30.20.42
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

a=ptime:20

009721: Oct 1 17:51:07.651: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3FB345AC
009722: Oct 1 17:51:07.651: ISDN Se0/1/0:15 Q931: TX -> CALL_PROC pd = 8 callref = 0x817B
Channel ID i = 0xA98381
Exclusive, Channel 1
009723: Oct 1 17:51:08.147: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone IST to SIP default timezone = GMT
009724: Oct 1 17:51:08.147: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3FB345AC with refCount = 1
009725: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg..
009726: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added.
009727: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Event/sipSPICreateRpid: Received Octet3A=0x83 -> Setting ;screen=yes ;privacy=off
SIP: (8771631) Group (a= group line) attribute, level 65535 instance 1 not found.
009728: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009729: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2416C2EC to Invite
009730: Oct 1 17:51:08.147: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 244
009731: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009732: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009733: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Transport/sipSPITransportSendMessage: msg=0x3FB345AC, addr=132.149.98.11, port=5060, sentBy_port=0, local_addr=10.30.20.42, is_req=1, transport=1, switch=0, callBack=0x0
009734: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009735: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009736: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009737: Oct 1 17:51:08.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:132.149.98.11, rport:5060 with laddr:10.30.20.42

009738: Oct 1 17:51:08.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x23D40108 is already on connection=0x222642D8 context_list
009739: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x3FB345AC
009740: Oct 1 17:51:08.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3FB345AC, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connId=3 vrfid=0 for UDP
009741: Oct 1 17:51:08.147: //8771631/E399B37DBF20/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:6623@132.149.98.11:5060 SIP/2.0
Via: SIP/2.0/UDP 10.30.20.42:5060;branch=z9hG4bKEA4376A
Remote-Party-ID: <sip:919967147467@10.30.20.42>;party=calling;screen=yes;privacy=off
From: <sip:919967147467@10.30.20.42>;tag=7D09A3DC-F58
To: <sip:6623@132.149.98.11>
Date: Fri, 01 Oct 2021 17:51:08 GMT
Call-ID: E39CC0DD-21E811EC-86909D61-D45772BD@10.30.20.42
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 3818500989-0568857068-3206610011-0969130848
User-Agent: Cisco-SIPGateway/IOS-15.4.3.M8
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70

Timestamp: 1633090868
Contact: <sip:919967147467@10.30.20.42:5060>
Call-Info: <sip:10.30.20.42:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 244

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

009742: Oct 1 17:51:08.147: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3FB345AC
009743: Oct 1 17:51:09.147: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone IST to SIP default timezone = GMT
009744: Oct 1 17:51:09.147: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3FB345AC with refCount = 1
009745: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg..
009746: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added.
009747: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Event/sipSPICreateRpid: Received Octet3A=0x83 -> Setting ;screen=yes ;privacy=off
SIP: (8771631) Group (a= group line) attribute, level 65535 instance 1 not found.
009748: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009749: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2416C2EC to Invite
009750: Oct 1 17:51:09.147: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 244
009751: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009752: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009753: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Transport/sipSPITransportSendMessage: msg=0x3FB345AC, addr=132.149.98.11, port=5060, sentBy_port=0, local_addr=10.30.20.42, is_req=1, transport=1, switch=0, callBack=0x0
009754: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009755: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009756: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009757: Oct 1 17:51:09.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:132.149.98.11, rport:5060 with laddr:10.30.20.42

009758: Oct 1 17:51:09.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x23D40108 is already on connection=0x222642D8 context_list
009759: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x3FB345AC
009760: Oct 1 17:51:09.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3FB345AC, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connId=3 vrfid=0 for UDP
009761: Oct 1 17:51:09.147: //8771631/E399B37DBF20/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:6623@132.149.98.11:5060 SIP/2.0

Via: SIP/2.0/UDP 10.30.20.42:5060;branch=z9hG4bKEA4376A
Remote-Party-ID: <sip:919967147467@10.30.20.42>;party=calling;screen=yes;privacy=off
From: <sip:919967147467@10.30.20.42>;tag=7D09A3DC-F58
To: <sip:6623@132.149.98.11>
Date: Fri, 01 Oct 2021 17:51:09 GMT
Call-ID: E39CC0DD-21E811EC-86909D61-D45772BD@10.30.20.42
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 3818500989-0568857068-3206610011-0969130848
User-Agent: Cisco-SIPGateway/IOS-15.4.3.M8
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1633090869
Contact: <sip:919967147467@10.30.20.42:5060>
Call-Info: <sip:10.30.20.42:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp

Content-Disposition: session;handling=required
Content-Length: 244

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

009762: Oct 1 17:51:09.147: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3FB345AC
009763: Oct 1 17:51:11.147: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone IST to SIP default timezone = GMT
009764: Oct 1 17:51:11.147: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3FB345AC with refCount = 1
009765: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg..
009766: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added.
009767: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Event/sipSPICreateRpid: Received Octet3A=0x83 -> Setting ;screen=yes ;privacy=off
SIP: (8771631) Group (a= group line) attribute, level 65535 instance 1 not found.
009768: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009769: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2416C2EC to Invite
009770: Oct 1 17:51:11.147: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 244
009771: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009772: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009773: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Transport/sipSPITransportSendMessage: msg=0x3FB345AC, addr=132.149.98.11, port=5060, sentBy_port=0, local_addr=10.30.20.42, is_req=1, transport=1, switch=0, callBack=0x0
009774: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009775: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009776: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009777: Oct 1 17:51:11.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:132.149.98.11, rport:5060 with laddr:10.30.20.42

009778: Oct 1 17:51:11.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x23D40108 is already on connection=0x222642D8 context_list
009779: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x3FB345AC
009780: Oct 1 17:51:11.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3FB345AC, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connId=3 vrfid=0 for UDP
009781: Oct 1 17:51:11.147: //8771631/E399B37DBF20/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:6623@132.149.98.11:5060 SIP/2.0
Via: SIP/2.0/UDP 10.30.20.42:5060;branch=z9hG4bKEA4376A
Remote-Party-ID: <sip:919967147467@10.30.20.42>;party=calling;screen=yes;privacy=off
From: <sip:919967147467@10.30.20.42>;tag=7D09A3DC-F58
To: <sip:6623@132.149.98.11>
Date: Fri, 01 Oct 2021 17:51:11 GMT
Call-ID: E39CC0DD-21E811EC-86909D61-D45772BD@10.30.20.42

Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 3818500989-0568857068-3206610011-0969130848
User-Agent: Cisco-SIPGateway/IOS-15.4.3.M8
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1633090871
Contact: <sip:919967147467@10.30.20.42:5060>
Call-Info: <sip:10.30.20.42:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 244

v=0
o=CiscoSystemsSIP-GW-UserAgent 5083 6944 IN IP4 10.30.20.42
s=SIP Call
c=IN IP4 10.30.20.42

t=0 0
m=audio 32608 RTP/AVP 0 101
c=IN IP4 10.30.20.42
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

009782: Oct 1 17:51:11.147: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3FB345AC
009783: Oct 1 17:51:15.147: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone IST to SIP default timezone = GMT
009784: Oct 1 17:51:15.147: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x3FB345AC with refCount = 1
009785: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Info/critical/4096/ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg..
009786: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Info/critical/1024/sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added.
009787: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Event/sipSPICreateRpid: Received Octet3A=0x83 -> Setting ;screen=yes ;privacy=off
SIP: (8771631) Group (a= group line) attribute, level 65535 instance 1 not found.
009788: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Info/info/34816/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
009789: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Info/info/4096/sipSPISendInvite: Associated container=0x2416C2EC to Invite
009790: Oct 1 17:51:15.147: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 244
009791: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
009792: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
009793: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Transport/sipSPITransportSendMessage: msg=0x3FB345AC, addr=132.149.98.11, port=5060, sentBy_port=0, local_addr=10.30.20.42, is_req=1, transport=1, switch=0, callBack=0x0
009794: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009795: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
009796: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
009797: Oct 1 17:51:15.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:132.149.98.11, rport:5060 with laddr:10.30.20.42

009798: Oct 1 17:51:15.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: gcb=0x23D40108 is already on connection=0x222642D8 context_list
009799: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x3FB345AC
009800: Oct 1 17:51:15.147: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x3FB345AC, addr=132.149.98.11, port=5060, local_addr=10.30.20.42, connId=3 vrfid=0 for UDP
009801: Oct 1 17:51:15.147: //8771631/E399B37DBF20/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:6623@132.149.98.11:5060 SIP/2.0
Via: SIP/2.0/UDP 10.30.20.42:5060;branch=z9hG4bKEA4376A
Remote-Party-ID: <sip:919967147467@10.30.20.42>;party=calling;screen=yes;privacy=off
From: <sip:919967147467@10.30.20.42>;tag=7D09A3DC-F58
To: <sip:6623@132.149.98.11>
Date: Fri, 01 Oct 2021 17:51:15 GMT
Call-ID: E39CC0DD-21E811EC-86909D61-D45772BD@10.30.20.42
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 3818500989-0568857068-3206610011-0969130848
User-Agent: Cisco-SIPGateway/IOS-15.4.3.M8
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER

CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1633090875
Contact: <sip:919967147467@10.30.20.42:5060>
Call-Info: <sip:10.30.20.42:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 244

v=0
o=CiscoSystemsSIP-GW-UserAgent 5083 6944 IN IP4 10.30.20.42
s=SIP Call
c=IN IP4 10.30.20.42
t=0 0
m=audio 32608 RTP/AVP 0 101
c=IN IP4 10.30.20.42
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

a=ptime:20

009802: Oct 1 17:51:15.147: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x3FB345AC
009803: Oct 1 17:51:17.695: ISDN Se0/1/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0x017B
Cause i = 0x82E6 - Recovery on timer expiry
009804: Oct 1 17:51:17.695: ISDN Se0/1/0:15 Q931: TX -> RELEASE pd = 8 callref = 0x817B
009805: Oct 1 17:51:17.695: //8771630/E399B37DBF20/CCAPI/cc_api_call_disconnected:
Cause Value=102, Interface=0x23E1208C, Call Id=8771630
009806: Oct 1 17:51:17.695: //8771630/E399B37DBF20/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=FALSE, Cause Value=102, Retry Count=0)
009807: Oct 1 17:51:17.695: //8771631/E399B37DBF20/SIP/Info/verbose/8192/ccsip_call_statistics: Requesting stats for callid=8771631
009808: Oct 1 17:51:17.695: //8771631/E399B37DBF20/SIP/Info/critical/8192/ccsip_call_statistics: Stats request failed for callid=8771631, dstCallID=-1, rc=-7
009809: Oct 1 17:51:17.695: //8771631/E399B37DBF20/CCAPI/ccCallDisconnect:
Cause Value=102, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
009810: Oct 1 17:51:17.695: //8771631/E399B37DBF20/CCAPI/ccCallDisconnect:
Cause Value=102, Call Entry(Responsed=FALSE, Cause Value=102)
009811: Oct 1 17:51:17.695: //8771631/E399B37DBF20/SIP/Info/verbose/4096/ccsip_ipip_media_service_get_event_data: Event id = 29
009812: Oct 1 17:51:17.695: //8771631/E399B37DBF20/SIP/Info/critical/32768/ccsip_ipip_media_forking_post_event: MF: Not a Anchor SIP leg..
009813: Oct 1 17:51:17.695: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
009814: Oct 1 17:51:17.695: //8771630/E399B37DBF20/CCAPI/ccCallDisconnect:
Cause Value=102, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=102)
009815: Oct 1 17:51:17.695: //8771630/E399B37DBF20/CCAPI/ccCallDisconnect:
Cause Value=102, Call Entry(Responsed=TRUE, Cause Value=102)
009816: Oct 1 17:51:17.695: //8771630/E399B37DBF20/CCAPI/cc_api_get_transfer_info:
Transfer Number=NULL
009817: Oct 1 17:51:17.695: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8
009818: Oct 1 17:51:17.695: //8771631/E399B37DBF20/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SPI_EVENT
009819: Oct 1 17:51:17.699: //8771631/E399B37DBF20/SIP/Info/info/8192/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
009820: Oct 1 17:51:17.699: //8771631/E399B37DBF20/SIP/Info/critical/8192/sipSPIValidateGtd: Signal Forward disabled
009821: Oct 1 17:51:17.699: //8771631/E399B37DBF20/SIP/Info/critical/8192/sipSPIValidateTunnelData: RawMsg/QSIG Tunneling Not Enabled
009822: Oct 1 17:51:17.699: //8771631/E399B37DBF20/SIP/Info/info/133120/sipSPIBwCacReleaseDialPeerBw: bwcac dial-peer bw 80 Kbps released for tag 100 active bw 0 Kbps
009823: Oct 1 17:51:17.699: //8771631/E399B37DBF20/SIP/Info/info/131072/sipSPIBwCacReleaseInterfaceBw: bwcac releasing interface GigabitEthernet0/0 bw 80 Kbps
009824: Oct 1 17:51:17.699: //8771631/E399B37DBF20/SIP/Info/info/131072/sipSPIBwCacReleaseAccountedBw: bwcac released accounted bw 80000 bps
009825: Oct 1 17:51:17.699: //8771631/E399B37DBF20/SIP/Info/notify/4096/act_sentinvite_disconnect: Received POTS Disconnect - Holding CANCEL till we receive a response from remote end.
009826: Oct 1 17:51:17.699: //8771631/E399B37DBF20/SIP/Info/info/4096/act_sentinvite_disconnect: Using cancel pending instead of trying timer
009827: Oct 1 17:51:17.735: ISDN Se0/1/0:15 Q931: RX <- RELEASE_COMP pd = 8 callref = 0x017B
009828: Oct 1 17:51:17.735: //8771630/E399B37DBF20/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x23E1208C, Tag=0x0, Call Id=8771630,
Call Entry(Disconnect Cause=102, Voice Class Cause Code=0, Retry Count=0)
009829: Oct 1 17:51:17.735: //8771630/E399B37DBF20/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
009830: Oct 1 17:51:17.735: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

009831: Oct 1 17:51:17.735: :cc_free_feature_vsa freeing 3A2017E0
009832: Oct 1 17:51:17.735: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

009833: Oct 1 17:51:17.735: vsacount in free is 2

 

 

Labels:
0 Helpful
9 Replies 9

Scott Leport
Level 7
Level 7

‎10-06-2021 03:04 AM

Hi,

 

Based on that debug, the gateway is sending INVITE messages to CUCM, but is not receiving a 100 TRYING back from CUCM. Subsequent INVITE messages are being sent, but the gateway is not receiving any response so the call times out and with a disconnect cause code of 102.

 

This error message in your trace sticks out:

 

009556: Oct 1 17:51:07.639: //8771631/E399B37DBF20/SIP/Error/sipSPIGetCallServerGroupTargets:
No server group configured

 

Can you confirm that your dial-peers facing CUCM are setup with a session target or with a server-group configuration referencing CUCM IP addresses?

Where is the new Firewall placed in the network? Behind or in front of the CUBE?

Have the Firewall team provided evidence that the port range is not being blocked / denied?

 

It may also be helpful to supply a copy of your configuration as that may also provide some clues.

mzee.sidd
Level 1
Level 1
In response to Scott Leport

‎10-06-2021 03:30 AM

Hi,

 

Yes, dial-peers have been configured with a session-target referencing the CUCM ip addresses.

 

PFB config for your reference:

voice service voip
ip address trusted list
media flow-around
allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip
fax protocol t38 version 0 ls-redundancy 0 hs-redundancy 0 fallback none
sip
bind control source-interface GigabitEthernet0/0.100
bind media source-interface GigabitEthernet0/0.100
registrar server
!
voice class codec 1
codec preference 1 g711ulaw
codec preference 2 g711alaw
codec preference 3 g729r8
!

dial-peer voice 100 voip
destination-pattern 6...
session protocol sipv2
session target ipv4:132.149.98.11
dtmf-relay rtp-nte sip-notify
codec g711ulaw
no vad

 

 

And they have placed the firewall in front of the VG so that was the reason we had shared the port details to be opened on the firewall as it is coming in between the CUCM and VG and they have confirmed that they had allowed the traffic with "any" "any" in the rules.

0 Helpful

Scott Leport
Level 7
Level 7
In response to mzee.sidd

‎10-06-2021 04:53 AM

If they have allowed all traffic and ICMP inspection enabled on the Firewall, you should be able to successfully ping between your CUBE and your CUCM. If you cannot, then IP routing would need to be verified end-to-end. If that's been proven, then I have a few other suggestions to move this along:

 

1. Can you configure a SIP keepalive profile on your CUCM facing dial-peers? Use the link below for reference.

2. On your CUCM SIP trunk to CUBE, can you enable OPTIONS ping in your SIP Profile which is attached to the trunk. Will need a reset of your SIP trunk after being enabled.

 

Just keen on finding out whether or not OPTIONS ping can be sent and received between CUCM and your CUBE. If it cannot, then engage the Firewall team again to check again.

 

Other steps which can be taken can be to make the same inbound call and take the CCM traces from RTMT and search for your call. That would at least prove that the call is getting to CUCM. If it's not, then narrow the troubleshooting focus back to Firewall & CUBE. 

 

Adding a SIP keepalive profile to a dial-peer:

https://www.cisco.com/c/en/us/td/docs/ios-xml/ios/voice/cube_sip/configuration/15-mt/cube-sip-15-mt-book/oodo-ping-group.html

Maren Mahoney
VIP
VIP
In response to mzee.sidd

‎10-06-2021 08:12 AM

Also check: With SIP bound to gi 0/0.100 on the router, is that the IP address the SIP Trunk in CUCM is configured with? If the SIP Trunk in CUCM is configured with a different IP address, that would cause it to not respond to the router.

The trace file for the Cisco CallManager service should show the incoming INVITE and the reason why CUCM is not responding. Or if the INVITE from the router does not appear at all in the trace file, this would tell us that the INVITE is being blocked by a FW or something.

Do you have just the one CUCM call processing node in your cluster?

Maren

mzee.sidd
Level 1
Level 1
In response to Maren Mahoney

‎10-08-2021 05:01 AM

Hi Maren,

 

They are using the same subnet for data and voice so after introducing the firewall in front of the Gateway they configured the same IP(of Gig 0/0.100) on the firewall and kept the Gig 0/0.100 interface administratively down so for testing we configured the Gig 0/0 IP on the SIP trunk in CUCM as per their provided IP to be used for SIP trunk and also changed the interface details to Gig 0/0 on the bind command under sip.

mzeesidd_0-1633694298790.png

Now , we have asked the network team to check the IP routing part on the gateway as this gateway was also working as WAN router before.

0 Helpful

Roger Kallberg
VIP
VIP
In response to mzee.sidd

‎10-09-2021 12:34 AM - edited ‎10-09-2021 12:42 AM

If okay by you I have some questions about your setup. Here go.

  • What is your SBC used for?
  • What is the primary reason for putting a firewall between the SBC and CM?

Reason for asking is that “normally” a firewall would be place in-between an untrusted network and the device to protect, and for what reason would you need to provide protection between the SBC and CM? The use case of a SBC is to form a boundary between networks/services, for example between an ITSP delivery of a PSTN SIP service and an on-prem telephony service like CM. With this in mind the common place to put the firewall, if one is used at all, would be between the ITSP and the SBC.

Apart from this as the rule set is allow Any to Any it would not really provide any protection anyway, so it sound rather pointless IMHO.



Response Signature


mzee.sidd
Level 1
Level 1
In response to Roger Kallberg

‎10-09-2021 12:43 AM

Hi Roger,

 

Customer is using the router for WAN as well as voice services for PSTN with SRST. And they had put the firewall in front of this router and ,for testing purpose they had set the rule to Any to Any but still the outbound PSTN call is getting disconnected , and for inbound call - call is landed on the extension but there is no voice on it.

 

Currently, we have asked the network team to check IP routing end to end and also to firewall team to check any blocked traffic related to voice subnet.

0 Helpful

Roger Kallberg
VIP
VIP
In response to mzee.sidd

‎10-09-2021 04:10 AM

So the SIP service is running on top of the WAN service provider service, ie it’s is running via their private network?



Response Signature


0 Helpful

Tirtha Tripathy
Cisco Employee
Cisco Employee

‎10-09-2021 11:37 PM

As per the problem description, this issue started after introducing the Firewall.
Hence the issue is a configuration issue on Firewall.

 

We need not change anything on CUCM and GW except workaround like changing the protocol from UDP to TCP which might be honored by firewall.

 

Check on Firewall for drop of SIP messages and fix them.

 

- TT

 

Regards, Tirtha
Customers Also Viewed These Support Documents