ZBF
Зарегистрирован: 23 июн 2014, 09:23 Сообщения: 6
|
Добрый день. У всего офиса перестала работать переадресация на сип телефонах, когда переадресация стоит на самом телефоне. Тишина в трубке, после таймаута в 20 секунд сброс звонка. Диалпиры не менялись, иос обновлял не помогло. Переадресация из конфига(call-forward b2bua all *) работает. Есть мысли? Заранее благодарю.
CISCO2921-K9 System image file is "flash:c2900-universalk9-mz.SPA.155-2.T4.bin"
sh run ! voice service voip ip address trusted list ipv4 10.151.192.101 255.255.255.255 ipv4 10.10.10.0 255.255.255.0 ipv4 10.150.192.5 255.255.255.255 ipv4 10.150.100.5 255.255.255.255 ipv4 10.150.198.5 255.255.255.255 ipv4 192.168.198.1 255.255.255.255 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 h323 h225 display-ie ccm-compatible no call service stop h245 tunnel disable h245 passthru all sip registrar server ! voice register dn 49 number 6222 allow watch name test label test ! voice register pool 41 id mac 6CF0.4956.ABB6 number 1 dn 49 dtmf-relay sip-notify voice-class codec 1 username 6222 password 6222 ! ..
debug voice translation ! 002542: Jan 29 15:37:17.328 ALM: --1-D36FE9AFB995-RXRULE-regxrule_stack_pop_RegXruleNumInfo: stack=0xC2E40D50; count=1 002543: Jan 29 15:37:17.328 ALM: --1-D36FE9AFB995-RXRULE-regxrule_stack_pop_callinfo_internal: numinfo=0xC24EEEF0 002544: Jan 29 15:37:17.328 ALM: --1-D36FE9AFB995-RXRULE-regxrule_stack_push_RegXruleNumInfo_internal: stack=0xC2E40D50; count=1 002545: Jan 29 15:37:17.332 ALM: --1-D36FE9AFB995-RXRULE-regxrule_stack_pop_RegXruleNumInfo: stack=0xC2E40D50; count=1 002546: Jan 29 15:37:17.332 ALM: --1-D36FE9AFB995-RXRULE-regxrule_stack_pop_callinfo_internal: numinfo=0xC24EEEF0 002547: Jan 29 15:37:17.332 ALM: --1-D36FE9AFB995-RXRULE-regxrule_stack_push_RegXruleNumInfo_internal: stack=0xC2E40D50; count=1 002548: Jan 29 15:37:17.332 ALM: --1-xxxxxxxxxxxx-RXRULE-sed_subst: No match! number= matchPattern=id; |[; ]*id$ replacePattern= !
debug ccsip translate ! 002577: Jan 29 15:38:53.516 ALM: -18100-0CBC64C8B9B3-SIP-Xlate-ccsip_api_redirect_call: Redirect to session: incoming redirect-target Tag(40020) [3790] !
debug ccsip error ! 002578: Jan 29 15:39:44.132 ALM: -18108-2AEDD698B9CD-SIP-Error-sipSPIGetCallServerGroupTargets: No server group configured 002579: Jan 29 15:39:44.132 ALM: -18108-2AEDD698B9CD-SIP-Error-sipSPI_ipip_vcc_ResetXcoder: Failed to post 195 event.. SIP: (18108) Group (a= group line) attribute, level 65535 instance 1 not found. 002580: Jan 29 15:39:49.768 ALM: -18103-210958AD8649-SIP-Error-sipSPIFlushDeferredQueue: Invalid deferredQueue 002581: Jan 29 15:39:49.852 ALM: -18101-1B59A7298643-SIP-Error-sipSPIFlushDeferredQueue: Invalid deferredQueue !
sh call history voice last 1 ! GENERIC: SetupTime=533612080 ms (15:41:31.518 ALM Mon Jan 29 2018) Index=10193 PeerAddress=3888 PeerSubAddress= PeerId=1020 PeerIfIndex=226 LogicalIfIndex=0 DisconnectCause=66 DisconnectText=recovery on timer expiry (102) ConnectTime=0 ms (0) DisconnectTime=533672160 ms (15:42:31.598 ALM Mon Jan 29 2018) CallDuration=00:00:00 sec CallOrigin=2 ReleaseSource=2 ChargedUnits=0 InfoType=speech TransmitPackets=0 TransmitBytes=0 ReceivePackets=0 ReceiveBytes=0 VOIP: ConnectionId[0x6AF2E4F6 0x40F11E8 0xBA17D9A8 0xD51A64C4] IncomingConnectionId[0x6AF2E4F6 0x40F11E8 0xBA17D9A8 0xD51A64C4] CallID=18118 SessionId=0 CallReferenceId=0 CallServiceType=Unknown RTP Loopback Call=FALSE RemoteIPAddress=10.150.192.5 RemoteUDPPort=0 RemoteSignallingIPAddress=10.150.192.5 RemoteSignallingPort=55286 RemoteMediaIPAddress=0.0.0.0 RemoteMediaPort=0 SRTP = off TextRelay = off Fallback Icpif=0 Fallback Loss=0 Fallback Delay=0 RoundTripDelay=0 ms SelectedQoS=best-effort tx_DtmfRelay=inband-voice FastConnect=FALSE
AnnexE=FALSE
Separate H245 Connection=FALSE
H245 Tunneling=FALSE
SessionProtocol=cisco ProtocolCallId= SessionTarget= SafEnabled=FALSE OnTimeRvPlayout=0 GapFillWithSilence=0 ms GapFillWithPrediction=0 ms GapFillWithInterpolation=0 ms GapFillWithRedundancy=0 ms HiWaterPlayoutDelay=0 ms LoWaterPlayoutDelay=0 ms Transcoded : No ReceiveDelay=0 ms LostPackets=0 EarlyPackets=0 LatePackets=0 VAD = enabled CoderTypeRate=g729r8 pre-ietf CodecBytes=0 cvVoIPCallHistoryIcpif=0 MediaSetting=flow-through CallerName=****. CallerIDBlocked=False OriginalCallingNumber=3888 OriginalCallingOctet=0x80 OriginalCalledNumber=6222 OriginalCalledOctet=0x80 OriginalRedirectCalledNumber= OriginalRedirectCalledOctet=0xFF DestinationRouteStr= TranslatedCallingNumber=3888 TranslatedCallingOctet=0x80 TranslatedCalledNumber=6222 TranslatedCalledOctet=0x80 TranslatedRedirectCalledNumber= TranslatedRedirectCalledOctet=0xFF GwReceivedCalledNumber=6222 GwReceivedCalledOctet3=0x80 GwReceivedCallingNumber=3888 GwReceivedCallingOctet3=0x80 GwReceivedCallingOctet3a=0x0 MediaInactiveDetected=no MediaInactiveTimestamp= MediaControlReceived= LongDurationCallDetected=no LongDurationCallTimerStamp= LongDurationCallDuration= Username= MlppServiceDomainNW=0 (none) MlppServiceDomainID= PrecedenceLevel=0 (PRECEDENCE_LEVEL_NONE) RTCP TransmitPackets=0 RTCP ReceivePackets=0 !
Звоню с номера 3888 на номер 6222(на котором стоит переадресация на номер 3790) debug ccsip all ! 002590: Jan 29 15:45:49.020 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-4096-sipSPIAddContextToTable: Added context(0x222A2CA8) with key=[9803] to table 002591: Jan 29 15:45:49.020 ALM: --1-000000000000-SIP-Info-info-4096-ccsip_ipip_media_service_init: 002592: Jan 29 15:45:49.020 ALM: --1-000000000000-SIP-Info-info-4096-ccsip_tdmip_media_service_init: 002593: Jan 29 15:45:49.020 ALM: --1-000000000000-SIP-Info-verbose-36864-ccsip_ipip_media_forking_init: MF: Queue is initialised.. 002594: Jan 29 15:45:49.020 ALM: -18167-000000000000-SIP-State-sipSPIChangeState: 0x222A2CA8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) 002595: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-critical-32768-ccsip_ipip_media_forking_read_from_TDContainer: MF: Unable to read data from TD Container.. 002596: Jan 29 15:45:49.024 ALM: -18167-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.. 002597: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-verbose-4096-ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 1, Event Id: EV_UNDEFINED 002598: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-verbose-4096-ccsip_iwf_map_ccapi_event_to_iwf_event: IWF Event: E_SIP_IWF_EV_SET_MODE 002599: Jan 29 15:45:49.024 ALM: -18167-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 002600: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-State-ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container 002601: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_get_int_type_frm_set_mode_ev: 002602: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-is_mode_sip_sip_md_snr: 002603: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_get_int_type_frm_set_mode_ev: 002604: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-is_mode_sip_sip_ed_snr: 002605: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_get_int_type_frm_set_mode_ev: 002606: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-is_mode_sip_sip_md: 002607: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_get_int_type_frm_set_mode_ev: 002608: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-is_mode_sip_sip_ed: 002609: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_get_int_type_frm_set_mode_ev: 002610: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-is_mode_sip_h32x_in_set_mode: 002611: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_get_int_type_frm_set_mode_ev: 002612: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-is_mode_sip_h323_in_set_mode: 002613: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-sip_iwf_h323_set_mode_hdlr: 002614: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-1-sip_iwf_h323_set_mode_hdlr: Setting SPI mode to SIP-H323 002615: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-State-ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_h323_container 002616: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-State-ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE 002617: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_iwf_handle_peer_event: Return value: SIP_IWF_SUCCESS 002618: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-verbose-4096-ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: CC_EV_IF_DIAG_DONE 002619: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-verbose-4096-ccsip_iwf_map_ccapi_event_to_iwf_event: IWF Event: E_SIP_IWF_EV_SET_FLOW_MODE 002620: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-State-ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_h323_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SET_FLOW_MODE 002621: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-State-ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container 002622: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-is_fa2ft_md_flow_mode_transition: 002623: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-is_fa2ft_flow_mode_transition: 002624: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_get_flow_mode_frm_set_flow_mode_ev: 002625: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-is_fa2ft_flow_mode_transition: 002626: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_get_flow_mode_frm_set_flow_mode_ev: 002627: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-verbose-4096-ccsip_iwf_process_event: IWF - cnfsm ret 2 002628: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_iwf_handle_peer_event: Return value: SIP_IWF_SUCCESS 002629: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ipip = 200000 002630: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_call_setup_request: This a IPIP call: Chan 0, codec 5 channel 28790, ip 10.150.192.5:28790 params 0x42EE154C caps 0x4042590C 002631: Jan 29 15:45:49.024 ALM: -18167-000000000000-SIP-Info-info-4096-ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipip = 200000 002632: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-2048-sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 002633: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Error-sipSPIGetCallServerGroupTargets: No server group configured 002634: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-5120-ccsip_call_setup_request: No dest server group configured 002635: Jan 29 15:45:49.024 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-5120-sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : 192.168.193.116 target_port : 5060
002636: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-4096-sipSPIUaddccCallIdToTable: Adding call id 46F7 to table 002637: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-131072-ccsip_call_setup_request: Incrementing call counter to [1] in dial-peer [40020] 002638: Jan 29 15:45:49.024 ALM: --1-xxxxxxxxxxxx-SIP-Event-sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP 002639: Jan 29 15:45:49.024 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-4096-ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 2 002640: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-2049-sipSPIGetCallConfig: preferred_codec set[0] type :No Codec bytes: 0 002641: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-2048-sipSPI_ipip_store_config_info: Setting mid_call_config_info = 0x0 for callid = 18167 002642: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8192-sipSPIGetCallConfig: Media forking disabled 002643: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-32768-sipSPIGetCallConfig: Media Antitrombone disabled 002644: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-131072-sipSPICanSetFallbackFlag: Local Fallback is not active 002645: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-65536-ccsip_sipline_set_vrf: Phone number 6222 from ccb called number 002646: Jan 29 15:45:49.024 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-65536-ccsip_sipline_set_vrf: Obtained phone tag (41) from Dial-peer 002647: Jan 29 15:45:49.024 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-65536-ccsip_sipline_set_vrf: Got vrf 0 for phone tag 41 002648: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8192-sipSPIGetCallConfig: VRF id = 0 002649: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-65536-sipSPISetMediaFlowMode: Forcing the flow mode to FLOW-THROUGH for SIP line 002650: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8192-sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH 002651: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-2304-sipSPISetMediaFlowMode: xcoder high-density disabled 002652: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8192-sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH 002653: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-1-sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE 002654: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Media-sipSPICopyStunConfigFromPeerToCCB: STUN Usage is not enabled 002655: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-12288-sipSPIGetModemInfoPerCall: peer_callID=18166 002656: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-32768-ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg.. 002657: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8704-sipSPIGetCallConfig: Incoming: No defer BYE for last call stats 002658: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-1-ccsip_set_srtp_config: No Srtp configure for this leg. 002659: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8192-sipSPIGetCallConfig: Media forking disabled 002660: Jan 29 15:45:49.024 ALM: -18167-0474BBA5BAB1-SIP-Info-info-34816-ccsip_ipip_media_forking_anchor_leg_config: MF: en_p->encap_s.voIP.voipPeerCfgMediaClass = 0 002661: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-34816-ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer has no media class recorder. 002662: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-36864-sipSPIMFChangeState: MF: Prev state = 0 & New state = -1 002663: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-32768-ccsip_ipip_media_forking_anchor_leg_reset: MF: Anchor leg config reset done... 002664: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-32768-ccsip_ipip_media_forking_intra_frame_request_config: MF: FIR en_p->encap_s.voIP.voipPeerCfgMediaClass = 0 002665: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-32768-ccsip_ipip_media_forking_get_forked_leg_config: MF: This leg is not forked call leg. 002666: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-11264-ccsipInitDSCPPolicyInfo: No DSCP Profile configured, No RPH 2 DSCP Mapping and DSCP policing 002667: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-8192-sipSPIGetCallConfig: Initilise the DSCP policy 002668: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-8192-sipSPICheckFAAnatAssymetricOrDO2EO: Not a SIP-SIP call or not in FA mode 002669: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-2049-populate_vcc_data: Using Voice Class Codec, tag = 1 and offer-all is = FALSE 002670: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-8192-sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Line 002671: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-10240-sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0 002672: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-2048-sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0 002673: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-2048-sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 002674: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-10240-sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled 002675: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-5120-sipSPIValidateAndCopyOutboundHost: CCSIP: copy target_host to outbound_host 002676: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-1-preprocessSetup: This is a not a SIGO Call -, could be DM call 002677: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-State-ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_h323_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_INIT_CALL_SETUP 002678: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-sip_iwf_h323_init_call_setup_hdlr: 002679: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-1-sip_iwf_h323_copy_channelInfo_to_sdp: callid 18167, channels 0xC2A09CFC caps 0x4042590C 002680: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-1-sipSPI_ipip_copy_and_init_extended_caps_info: Peer cap provided: callid = 18167, peer dtmf = 0peer t38 version = 0 peer t38 maxBitRate = 14400 002681: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-4096-ccsip_ipip_media_service_get_event_data: Event id = 0 002682: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-4096-ccsip_ipip_media_service_get_event_data: Ans=0, Mid-call=0 002683: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-State-ccsip_cnfsm_debugs: IPIPMS:cur_container:ccsip_ipip_media_service_main_container, cur_state:S_IPIP_MEDIA_SERV_STATE_IDLE, event:E_IPIP_MEDIA_SERV_EV_PEER_CHNL_IND 002684: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-288-sipSPIDtmfTranscoder: Return upon SCCP version 0 002685: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-272-sipSPISrtpTranscoder: Checking if call is SRTP-RTP 002686: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-16-sipSPISrtpInterworking: Checking if SRTP Interworking case 002687: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8448-sipSPIAudioLevelAdjustmentTranscoder: AudioLevelAdjustment do not need xcoder 002688: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-8192-sipSPI_ipip_codec_byte_transrating: NOT SIP-SIP CALL. Will be addressed in future. 002689: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-33024-sipSPIupdateXcoderForCPA: XCODER NOT needed for CPA feature 002690: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-33024-sipSPIupdateXcoderForCNGFax: XCODER NOT needed for CNG Fax Detect feature 002691: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8448-sipSPICodecTranscoder: No body else needs xcoder. OFFER_ALL is intact 002692: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-256-sipSPI_ipip_vcc_CopyChannelInfoToCodecList: Codec added 5 002693: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-256-sipSPI_ipip_vcc_CheckCodecSetType: Check between Equalset & Subset.. 002694: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-1-codec_found: Codec to be matched: g711ulaw(5) 002695: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-1-codec_found: Match Found at index 1. 002696: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-256-sipSPI_ipip_vcc_CheckCodecSetType: Match found.. continue for next codec.. 002697: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-256-sipSPI_ipip_vcc_CheckCodecSetType: This is Subset 002698: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-1-sipSPICodecTranscoder: Codec set type is 2 002699: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-1-codec_found: Codec to be matched: g711ulaw(5) 002700: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-1-codec_found: Match Found at index 1. 002701: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-4352-sipSPI_ipip_vcc_ResetXcoder: Post to state machine.. 002702: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-4096-ccsip_ipip_media_service_get_event_data: Event id = 18 002703: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8192-ccsip_ipip_media_service_process_event: IPIP media service in use, deferring event 002704: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-4096-sipSPI_ipip_vcc_ResetXcoder: Posting event 195 to peer leg 002705: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Error-sipSPI_ipip_vcc_ResetXcoder: Failed to post 195 event.. 002706: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8448-sipSPIXcoderNotNeededRevertFlowMode: Xcoder is not needed 002707: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-131074-sipSPIBwCacCalcMaxAudioBandwidth: calculating max bw from preffered codecs (local offer) 002708: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-131074-sipSPIBwCacCalcMaxAudioBandwidth: max bw (excluding pak overhead) from preffered codecs: codec g711ulaw bw 64000 index 0 002709: Jan 29 15:45:49.028 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-16-sipSPIBwCacGetSrtpOverhead: Return: 0 002710: Jan 29 15:45:49.028 ALM: --1-xxxxxxxxxxxx-SIP-Info-notify-1-convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20 002711: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-131074-sipSPIBwCacCalcMaxAudioBandwidth: max bw (including pak overhead) from preffered codecs: codec g711ulaw bw 80000 002712: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-131080-sipSPIBwCacCalcMaxFaxBandwidth: No T.38 Fax negotiated 002713: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-14-ccsip_ipipms_peer_chnl_ind_hdlr: CHNL IND audio bw 80000 bps video bw 0 bps fax bw 0 bps 002714: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-4-sipSPI_ipip_get_video_channel_index: Peer Video Channel Index = 0, Total=1 002715: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-State-ccsip_cnfsm_debugs: IPIPMS:next_state:S_IPIP_MEDIA_SERV_STATE_INIT_XCODER_RESERVED 002716: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-State-ccsip_cnfsm_debugs: IPIPMS:next_state:S_IPIP_MEDIA_SERV_STATE_IDLE 002717: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-1-sipSPI_ipip_preprocess_call_setup: Container with extended caps previewinfo for peer callid 18166 removed 002718: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-State-ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE 002719: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-6-sipSPIValidateStreamAddrType: stream:1, Mode : 1 002720: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-513-resolve_media_ip_address_to_bind: peer_tag=40020 002721: Jan 29 15:45:49.028 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-8192-resolve_media_ip_address_to_bind: VRF id = 0 002722: Jan 29 15:45:49.028 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-8192-resolve_media_ip_address_to_bind: ip_best_local_address 10.10.10.222 for SIP 002723: Jan 29 15:45:49.028 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-8192-resolve_media_ip_address_to_bind: return addr 10.10.10.222 002724: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Media-sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.10.10.222 002725: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-1-sipSPIOutgoingCallSDP: Failure in creating outbound streams SIP: (18167) Group (a= group line) attribute, level 65535 instance 1 not found. 002726: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8192-resolve_sig_ip_address_to_bind: VRF id = 0 002727: Jan 29 15:45:49.028 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-8192-resolve_sig_ip_address_to_bind: ip_best_local_address 10.10.10.222 for SIP 002728: Jan 29 15:45:49.028 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-8192-resolve_sig_ip_address_to_bind: return addr 10.10.10.222 002729: Jan 29 15:45:49.028 ALM: --1-xxxxxxxxxxxx-SIP-Media-sipSPIReserveRtpPort: reserved port 26094 for stream 1 002730: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-1-sipSPIDoBearerCapToCodecMapping: Bearer capability to Codec Mapping: DISABLED
002731: Jan 29 15:45:49.028 ALM: --1-xxxxxxxxxxxx-SIP-Info-notify-1-convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20 002732: Jan 29 15:45:49.028 ALM: --1-xxxxxxxxxxxx-SIP-Info-notify-1-sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1 002733: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-8193-sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed 002734: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-info-1-sipSPIOutgoingCallSDP: Creating recv-only stream for outbound call 002735: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Media-sipSPIProcessRtpSessions: Processing stream state = STREAM_IDLE 002736: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Media-sipSPIProcessRtpSessions: No active streams. 002737: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-4096-sip_gw_pre_setup_update_stream_media_direction: peer_callID = 18166 002738: Jan 29 15:45:49.028 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-86016-sip_gw_pre_setup_update_stream_media_direction: call xfer scenario or SIP line, skip peer media_dir : 0 002739: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-1-sip_gw_pre_setup_add_sdp_container: SDP container added 002740: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-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 002741: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-131072-sipSPIBwCacUpdateInterfaceBw: bwcac acquiring interface Tunnel510 bw 80 002742: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-131072-sipSPIBwCacUpdateAccountedBw: bwcac update accounted bw (initial offer) accounted bw set to 80000 002743: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-133120-sipSPIBwCacIsDialPeerBwAvailable: bwcac NOP dial-peer bw available tag 40020 002744: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-1-sipSPIBwCacIsInterfaceBwAvailable: bwcac interface bw threshold not configured 002745: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-131072-sipSPIBwCacVerifyBwThreshold: bwcac verify bw threshold, bw available allow call total bw 80000 bps 002746: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-8192-sipSPIValidateGtd: Signal Forward disabled 002747: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-8192-sipSPIValidateTunnelData: RawMsg-QSIG Tunneling Not Enabled 002748: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-10240-sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg 002749: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-3072-sipSPIPreprocessUriFormat: Url cfg for 1: 2,phone-ctxt=FALSE 002750: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-9216-sipSPIAddCiscoGcid: Gcid value not set - not adding header. 002751: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-8192-sipSPIAddPrivacyandIdentityInfo: Removing "id" value from Privacy 002752: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-2048-sipSPICompareHistoryInfoWithMatchedDialpeer: call-route history-info CLI not enabled 002753: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-1024-sipSPI_ipip_set_history_info_header: No HI header recvd from container 002754: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8192-resolve_sig_ip_address_to_bind: VRF id = 0 002755: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-8192-resolve_sig_ip_address_to_bind: ip_best_local_address 10.10.10.222 for SIP 002756: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-8192-resolve_sig_ip_address_to_bind: return addr 10.10.10.222 002757: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-131072-sipSPIRscmsmAvail: Value returned by check is = 0 002758: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8192-resolve_sig_ip_address_to_bind: VRF id = 0 002759: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-8192-resolve_sig_ip_address_to_bind: ip_best_local_address 10.10.10.222 for SIP 002760: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-8192-resolve_sig_ip_address_to_bind: return addr 10.10.10.222 002761: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-4096-sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x222A2CA8 5563B34-41011E8-86DFC530-7F5C6811@10.10.10.222 002762: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-4096-sipSPIUaddCcbToTable: Added to table. ccb=0x222A2CA8 key=5563B34-41011E8-86DFC530-7F5C6811@10.10.10.222 balance 0 002763: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-12288-sipSPIUsetBillingProfile: sipCallId for billing records = 5563B34-41011E8-86DFC530-7F5C6811@10.10.10.222 002764: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipSPIUpdateResponseInfo: Dialog Transaction Address 192.168.193.116,Port 5060, Transport 1, SentBy Port 5060vrfid 0 002765: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-8192-sipSPISetDateHeader: Converting TimeZone ALM to SIP default timezone = GMT 002766: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x24156844 with refCount = 1 002767: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Event-Session-Timer-sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ 002768: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Event-Session-Timer-sipSTSLMain: dir:1, method:102, resp_code:0, container:C2E42D28 002769: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-8192-Session-Timer-sipSTSLSRReqSend: Session timer is not required 002770: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-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 002771: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-ccsip_offer_ans_handle_sent_sdp: 002772: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-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 002773: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-ccsip_offer_ans_is_invite_offer_valid: TRUE 002774: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-ccsip_offer_ans_common_offer_sent_hdlr: 002775: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-ccsip_iwf_handle_network_event: 002776: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-State-ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_h323_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SENT_SDP 002777: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-is_call_leg_do: 002778: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-State-ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP 002779: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-State-ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_SENT 002780: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Info-critical-2048-sipSPIgetRegistrarHost: registrar is not configured 002781: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-4096-ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg.. 002782: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-1024-sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added. 002783: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Event-sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off 002784: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-sipSPISendInvite: Associated container=0xC2E42D28 to Invite 002785: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-8192-sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 215 002786: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPISendInvite: Sending Invite to the transport layer 002787: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE 002788: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPITransportSendMessage: msg=0x24156844, addr=192.168.193.116, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x35DEF5C8 002789: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-2048-sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 002790: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-2048-sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 002791: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPITransportSendMessage: Proceedable for sending msg immediately 002792: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipConnectionManagerGetConnection: connection required for raddr:192.168.193.116, rport:5060 with laddr:
002793: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipInstanceGetConnectionId: Registering gcb=0x222A2CA8 with connection=0x3EA14178 context list 002794: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipTransportLogicSendMsg: Set to send the msg=0x24156844 002795: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipTransportPostSendMessage: Posting send for msg=0x24156844, addr=192.168.193.116, port=5060, local_addr=, connId=14 vrfid=0 for UDP 002796: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-info-512-sentInviteRequest: Sent Invite in state STATE_IDLE 002797: Jan 29 15:45:49.032 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-4096-sentInviteRequest: Transaction active. Facilities will be queued. 002798: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-State-sipSPIChangeState: 0x222A2CA8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE) 002799: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Media-sipSPIProcessRtpSessions: Processing stream state = STREAM_ADDING 002800: Jan 29 15:45:49.032 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-6-sipSPIAddStream: set stream_callid from ccb->ccCallID:0x46F7, media_type:0 002801: Jan 29 15:45:49.036 ALM: -18167-0474BBA5BAB1-SIP-Media-sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 18167) to the VOIP RTP library 002802: Jan 29 15:45:49.036 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-6-sipSPIValidateStreamAddrType: stream:1, Mode : 1 002803: Jan 29 15:45:49.036 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-513-resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr 002804: Jan 29 15:45:49.036 ALM: -18167-0474BBA5BAB1-SIP-Media-sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.10.10.222 8376 IN IP4 10.10.10.222 s=SIP Call c=IN IP4 10.10.10.222 t=0 0 m=audio 26094 RTP-AVP 0 19 c=IN IP4 10.10.10.222 a=rtpmap:0 PCMU-8000 a=rtpmap:19 CN-8000 a=ptime:20
002827: Jan 29 15:45:49.036 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Freed msg=0x24156844 002828: Jan 29 15:45:49.872 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x24156844 with refCount = 1 002829: Jan 29 15:45:49.872 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x24D1CA00 with refCount = 1 002830: Jan 29 15:45:49.872 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-4096-HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [192.168.193.116]:5060, local_address:[ - ] 002831: Jan 29 15:45:49.872 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Freed msg=0x24156844 002832: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-8192-sipSPISetDateHeader: Converting TimeZone ALM to SIP default timezone = GMT 002833: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x24156844 with refCount = 1 002834: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-4096-ccsip_ipip_media_forking_get_forked_recording_data: MF: Not a Forked leg.. 002835: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-1024-sipSPICreateRecParticipantHeaders: X-Cisco-Recording-Participant header not added. 002836: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Event-sipSPICreateRpid: Received Octet3A=0x00 -> Setting ;screen=no ;privacy=off 002837: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-sipSPISendInvite: Associated container=0xC2E42D28 to Invite 002838: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-8192-sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 215 002839: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPISendInvite: Sending Invite to the transport layer 002840: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE 002841: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPITransportSendMessage: msg=0x24156844, addr=192.168.193.116, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0 002842: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Info-info-2048-sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 002843: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Info-info-2048-sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 002844: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPITransportSendMessage: Proceedable for sending msg immediately 002845: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipConnectionManagerGetConnection: connection required for raddr:192.168.193.116, rport:5060 with laddr:
002846: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipInstanceGetConnectionId: gcb=0x222A2CA8 is already on connection=0x3EA14178 context_list 002847: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipTransportLogicSendMsg: Set to send the msg=0x24156844 002848: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipTransportPostSendMessage: Posting send for msg=0x24156844, addr=192.168.193.116, port=5060, local_addr=, connId=14 vrfid=0 for UDP 002849: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-4096-ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 002850: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipTransportProcessNWNewConnMsg: context=0x0 002851: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-4096-ccsip_new_msg_preprocessor: Checking Invite Dialog 002852: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_lock: Increment msg (0x24D1CA00) counter, current msg->refCount = 2 002853: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Msg-ccsipDisplayMsg: Received: SIP-2.0 100 Trying To: <sip:6222@192.168.193.116> From: "***" <sip:3888@10.10.10.222>;tag=1FD2341C-3CE Call-ID: 5563B34-41011E8-86DFC530-7F5C6811@10.10.10.222 CSeq: 101 INVITE Via: SIP-2.0-UDP 10.10.10.222:5060;branch=z9hG4bKBBB211F Timestamp: 1517219149 Server: Linksys-SPA922-5.1.15(a) Content-Length: 0
002854: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-1024-sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX 002855: Jan 29 15:45:49.876 ALM: -18167-0474BBA5BAB1-SIP-State-sipSPIChangeState: 0x222A2CA8 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) 002856: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Decrement msg (0x24D1CA00) counter, current msg->refCount = 1 002857: Jan 29 15:45:49.876 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Freed msg=0x24D1CA00 002858: Jan 29 15:45:50.504 ALM: -18167-0474BBA5BAB1-SIP-Msg-ccsipDisplayMsg: Sent: INVITE sip:6222@192.168.193.116:5060 SIP-2.0 Via: SIP-2.0-UDP 10.10.10.222:5060;branch=z9hG4bKBBB211F Remote-Party-ID: "***" <sip:3888@10.10.10.222>;party=calling;screen=no;privacy=off From: "****" <sip:3888@10.10.10.222>;tag=1FD2341C-3CE To: <sip:6222@192.168.193.116> Date: Mon, 29 Jan 2018 09:45:49 GMT Call-ID: 5563B34-41011E8-86DFC530-7F5C6811@10.10.10.222 Supported: 100rel,timer,resource-priority,replaces Min-SE: 1800 Cisco-Guid: 0074759077-0068162024-3132217768-3575276740 User-Agent: Cisco-SIPGateway-IOS-15.5.2.T4 Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Max-Forwards: 70 Timestamp: 1517219149 Contact: <sip:3888@10.10.10.222:5060> Call-Info: <sip:10.10.10.222: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: 215
v=0 o=CiscoSystemsSIP-GW-UserAgent 2181 8376 IN IP4 10.10.10.222 s=SIP Call c=IN IP4 10.10.10.222 t=0 0 m=audio 26094 RTP-AVP 0 19 c=IN IP4 10.10.10.222 a=rtpmap:0 PCMU-8000 a=rtpmap:19 CN-8000 a=ptime:20
002859: Jan 29 15:45:50.504 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Freed msg=0x24156844 002860: Jan 29 15:45:50.516 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x24156844 with refCount = 1 002861: Jan 29 15:45:50.516 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x24D1CA00 with refCount = 1 002862: Jan 29 15:45:50.516 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-4096-HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [192.168.193.116]:5060, local_address:[ - ] 002863: Jan 29 15:45:50.516 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Freed msg=0x24156844 002864: Jan 29 15:45:50.516 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x24156844 with refCount = 1 002865: Jan 29 15:45:50.516 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x43B4E1CC with refCount = 1 002866: Jan 29 15:45:50.516 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-4096-HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [192.168.193.116]:5060, local_address:[ - ] 002867: Jan 29 15:45:50.516 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Freed msg=0x24156844 002868: Jan 29 15:45:50.520 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-4096-ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 002869: Jan 29 15:45:50.520 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipTransportProcessNWNewConnMsg: context=0x0 002870: Jan 29 15:45:50.520 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-4096-ccsip_new_msg_preprocessor: Checking Invite Dialog 002871: Jan 29 15:45:50.520 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_lock: Increment msg (0x24D1CA00) counter, current msg->refCount = 2 002872: Jan 29 15:45:50.520 ALM: -18167-0474BBA5BAB1-SIP-Msg-ccsipDisplayMsg: Received: SIP-2.0 302 Moved Temporarily To: <sip:6222@192.168.193.116>;tag=c3b5a895d9eb1e4ai0 From: "***" <sip:3888@10.10.10.222>;tag=1FD2341C-3CE Call-ID: 5563B34-41011E8-86DFC530-7F5C6811@10.10.10.222 CSeq: 101 INVITE Via: SIP-2.0-UDP 10.10.10.222:5060;branch=z9hG4bKBBB211F Timestamp: 1517219149 Contact: <sip:3790@10.150.198.5> Diversion: "6222" <sip:6222@10.150.198.5>;reason=unconditional Server: Linksys-SPA922-5.1.15(a) Content-Length: 0
002873: Jan 29 15:45:50.520 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-1024-sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX 002874: Jan 29 15:45:50.520 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x24156844 with refCount = 1 002875: Jan 29 15:45:50.520 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-ccsip_offer_ans_handle_call_active: 002876: Jan 29 15:45:50.520 ALM: -18167-0474BBA5BAB1-SIP-State-ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_OFFER_SENT, event:E_SIP_DIALOG_ESTD 002877: Jan 29 15:45:50.520 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-ccsip_offer_ans_process_event: O-A - cnfsm ret 2 002878: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-info-4096-sipSPISendAck: Associated container=0xC2E435C0 to Ack 002879: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-8192-sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 002880: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPISendAck: Sending ACK to the transport layer 002881: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE 002882: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPITransportSendMessage: msg=0x24156844, addr=192.168.193.116, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0 002883: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-info-2048-sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 002884: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-info-2048-sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 002885: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipSPITransportSendMessage: Proceedable for sending msg immediately 002886: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipConnectionManagerGetConnection: connection required for raddr:192.168.193.116, rport:5060 with laddr:
002887: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipInstanceGetConnectionId: gcb=0x222A2CA8 is already on connection=0x3EA14178 context_list 002888: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Transport-sipTransportLogicSendMsg: Set to send the msg=0x24156844 002889: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipTransportPostSendMessage: Posting send for msg=0x24156844, addr=192.168.193.116, port=5060, local_addr=, connId=14 vrfid=0 for UDP 002890: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Media-ccsip_api_redirect_call: Changing rtp session to receiver before redirecting. 002891: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Media-sipSPIUpdateRtpSession: stun is disabled for stream:C328E354 002892: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-16384-ccsip_api_redirect_call: redirect_contact 3790 002893: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-16384-sipSPI_ipip_PassthruContactHeader: peer_ccb is null..Could not add 302 contact in TD container 002894: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-16384-sipSPI_ipip_PassthruContactHeader: contact_passing = 0 002895: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-16384-sipSPI_ipip_build_contact: Contact sent1: <sip:3790@10.150.198.5:5060> 002896: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-10240-sipSPI_ipip_AddPassthruCopyListDataToTdContainer: Adding pass-thru data for tag: 91, event :11 002897: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-10240-sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0 002898: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-10240-sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue 002899: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-8192-sipSPI_ipip_IsContentPassthruEnabled: - 0 002900: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-notify-8192-sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled 002901: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-4096-sipSPISendRedirectInd: Unable to add headers into TD container 002902: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-1024-sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container 002903: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-65536-sipSPISendRedirectInd: is_iDivert = 0 002904: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-critical-4096-sipSPICheckOutBoundDpProvisioning: Cannot obtain the the header bitmap 002905: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-65536-sipSPISendRedirectInd: redirect_contact = 3790, ssOpPtr->cdRerouting.origCalledNum = 6222 002906: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Info-verbose-65536-sipSPISendRedirectInd: ssOpPtr->cdRerouting.redirectUrl = , ssOpPtr->cdRerouting.calledAddress = 3790
002907: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-State-sipSPIChangeState: 0x222A2CA8 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (SIP_STATE_REDIRECT_PENDING, SUBSTATE_NONE) 002908: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Decrement msg (0x24D1CA00) counter, current msg->refCount = 1 002909: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-4096-ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 002910: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipTransportProcessNWNewConnMsg: context=0x0 002911: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-4096-ccsip_new_msg_preprocessor: Checking Invite Dialog 002912: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_lock: Increment msg (0x43B4E1CC) counter, current msg->refCount = 2 002913: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Msg-ccsipDisplayMsg: Received: SIP-2.0 302 Moved Temporarily To: <sip:6222@192.168.193.116>;tag=c3b5a895d9eb1e4ai0 From: "****" <sip:3888@10.10.10.222>;tag=1FD2341C-3CE Call-ID: 5563B34-41011E8-86DFC530-7F5C6811@10.10.10.222 CSeq: 101 INVITE Via: SIP-2.0-UDP 10.10.10.222:5060;branch=z9hG4bKBBB211F Timestamp: 1517219149 Contact: <sip:3790@10.150.198.5> Diversion: "6222" <sip:6222@10.150.198.5>;reason=unconditional Server: Linksys-SPA922-5.1.15(a) Content-Length: 0
002914: Jan 29 15:45:50.524 ALM: %SIP-3-BADPAIR: Unexpected event 1 (SIPSPI_EV_NEW_MESSAGE) in state 26 (SIP_STATE_REDIRECT_PENDING) substate 0 (SUBSTATE_NONE) 002915: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Decrement msg (0x43B4E1CC) counter, current msg->refCount = 1 002916: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Freed msg=0x43B4E1CC 002917: Jan 29 15:45:50.524 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-4096-ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 32 002918: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-SIP-Event-Session-Timer-sipSTSLMain: Event: E_STSL_SPI_EVENT 002919: Jan 29 15:45:50.524 ALM: -18167-0474BBA5BAB1-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 002920: Jan 29 15:45:50.528 ALM: -18167-0474BBA5BAB1-SIP-Msg-ccsipDisplayMsg: Sent: ACK sip:6222@192.168.193.116:5060 SIP-2.0 Via: SIP-2.0-UDP 10.10.10.222:5060;branch=z9hG4bKBBB211F From: "****" <sip:3888@10.10.10.222>;tag=1FD2341C-3CE To: <sip:6222@192.168.193.116>;tag=c3b5a895d9eb1e4ai0 Date: Mon, 29 Jan 2018 09:45:49 GMT Call-ID: 5563B34-41011E8-86DFC530-7F5C6811@10.10.10.222 Max-Forwards: 70 CSeq: 101 ACK Allow-Events: telephone-event Content-Length: 0
002921: Jan 29 15:45:50.528 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Freed msg=0x24156844 002922: Jan 29 15:45:51.372 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x24156844 with refCount = 1 002923: Jan 29 15:45:51.372 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_create: created msg=0x43B4E1CC with refCount = 1 002924: Jan 29 15:45:51.372 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-4096-HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [192.168.193.116]:5060, local_address:[ - ] 002925: Jan 29 15:45:51.372 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Freed msg=0x24156844 002926: Jan 29 15:45:51.372 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-4096-ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 002927: Jan 29 15:45:51.372 ALM: --1-xxxxxxxxxxxx-SIP-Transport-sipTransportProcessNWNewConnMsg: context=0x0 002928: Jan 29 15:45:51.372 ALM: --1-xxxxxxxxxxxx-SIP-Info-verbose-4096-ccsip_new_msg_preprocessor: Checking Invite Dialog 002929: Jan 29 15:45:51.376 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_lock: Increment msg (0x43B4E1CC) counter, current msg->refCount = 2 002930: Jan 29 15:45:51.376 ALM: -18167-0474BBA5BAB1-SIP-Msg-ccsipDisplayMsg: Received: SIP-2.0 302 Moved Temporarily To: <sip:6222@192.168.193.116>;tag=c3b5a895d9eb1e4ai0 From: "****" <sip:3888@10.10.10.222>;tag=1FD2341C-3CE Call-ID: 5563B34-41011E8-86DFC530-7F5C6811@10.10.10.222 CSeq: 101 INVITE Via: SIP-2.0-UDP 10.10.10.222:5060;branch=z9hG4bKBBB211F Timestamp: 1517219149 Contact: <sip:3790@10.150.198.5> Diversion: "6222" <sip:6222@10.150.198.5>;reason=unconditional Server: Linksys-SPA922-5.1.15(a) Content-Length: 0
002931: Jan 29 15:45:51.376 ALM: %SIP-3-BADPAIR: Unexpected event 1 (SIPSPI_EV_NEW_MESSAGE) in state 26 (SIP_STATE_REDIRECT_PENDING) substate 0 (SUBSTATE_NONE) 002932: Jan 29 15:45:51.376 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Decrement msg (0x43B4E1CC) counter, current msg->refCount = 1 002933: Jan 29 15:45:51.376 ALM: --1-xxxxxxxxxxxx-SIP-Info-info-1024-htt*pish_msg_free: Freed msg=0x43B4E1CC
|