LTB1-RACK4-RTRGATEWAY#debug ccs LTB1-RACK4-RTRGATEWAY#debug ccsip al LTB1-RACK4-RTRGATEWAY#debug ccsip all This may severely impact system performance. Continue? [confirm] All SIP Call tracing is enabled LTB1-RACK4-RTRGATEWAY# LTB1-RACK4-RTRGATEWAY# LTB1-RACK4-RTRGATEWAY# May 6 06:32:24.369: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x7F61DF8518F8) with key=[2218] to table May 6 06:32:24.373: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init: May 6 06:32:24.373: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init: May 6 06:32:24.373: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised.. May 6 06:32:24.374: //-1/000000000000/SIP/Info/verbose/4097/ccsip_platform_init_ccb: Initialising rtp session queue May 6 06:32:24.374: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 1000, sip_vrfid 0, voice_vrfid 0 May 6 06:32:24.374: //2218/000000000000/SIP/Info/verbose/8192/ccsip_ood_options_profile_ping_send: ccsip_ood_options_profile_ping_send: peer_tag = 1000, tenant_tag = 0, sig_tos=0x60 VRFId = 0 May 6 06:32:24.374: //2218/000000000000/SIP/State/sipSPIChangeState: 0x7F61DF8518F8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) May 6 06:32:24.374: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x7F61DF859148) with key=[2219] to table May 6 06:32:24.374: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init: May 6 06:32:24.374: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init: May 6 06:32:24.374: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised.. May 6 06:32:24.374: //-1/000000000000/SIP/Info/verbose/4097/ccsip_platform_init_ccb: Initialising rtp session queue May 6 06:32:24.374: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 1000, sip_vrfid 0, voice_vrfid 0 May 6 06:32:24.374: //2219/000000000000/SIP/Info/verbose/8192/ccsip_ood_options_profile_ping_send: ccsip_ood_options_profile_ping_send: peer_tag = 1000, tenant_tag = 0, sig_tos=0x60 VRFId = 0 May 6 06:32:24.374: //2219/000000000000/SIP/State/sipSPIChangeState: 0x7F61DF859148 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) May 6 06:32:24.375: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 37 May 6 06:32:24.375: //2218/000000000000/SIP/Info/verbose/4096/sipSPIUaddccCallIdToTable: Adding call id 8AA to table May 6 06:32:24.375: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 1000, sip_vrfid 0, voice_vrfid 0 May 6 06:32:24.375: //2218/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 May 6 06:32:24.375: //2218/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 May 6 06:32:24.375: //2218/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: sip-ua conn_reuse configured May 6 06:32:24.375: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 172.16.30.9 for SIP May 6 06:32:24.375: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 172.16.30.9 for SIP May 6 06:32:24.375: //2218/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 172.16.30.9 May 6 06:32:24.375: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: bind_inuse: 1conn_reuse: 1 May 6 06:32:24.375: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 172.16.30.9 May 6 06:32:24.375: //2218/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x7F61DF8518F8 B4C083AE-297A11F0-88ABEB9E-95F6367F@172.16.30.9 May 6 06:32:24.375: //2218/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x7F61DF8518F8 key=B4C083AE-297A11F0-88ABEB9E-95F6367F@172.16.30.9 balance 1 May 6 06:32:24.375: //2218/000000000000/SIP/State/sipSPIChangeState: 0x7F61DF8518F8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) May 6 06:32:24.375: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x7F61E06B0688 with refCount = 1 May 6 06:32:24.375: //2218/000000000000/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 15 event May 6 06:32:24.376: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT May 6 06:32:24.376: //2218/000000000000/SIP/Error/sipSPIAddPrivacyHeader: Orig Container is NULL...should have value except in case of sending OOD Options ping. May 6 06:32:24.376: //2218/000000000000/SIP/Error/sipSPIAddAssertedIDHeader: Orig Container is NULL...should have value except in case of sending OOD Options ping. May 6 06:32:24.376: //2218/000000000000/SIP/Error/sipSPIAddPreferredIDHeader: Orig Container is NULL...should have value except in case of sending OOD Options ping. May 6 06:32:24.376: //2218/000000000000/SIP/Info/info/4096/sipSPISendOptionsRequest: Associated container=0x7F61D797D350 to Options May 6 06:32:24.376: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 May 6 06:32:24.376: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 1000, sip_vrfid 0, voice_vrfid 0 May 6 06:32:24.376: //2218/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE May 6 06:32:24.376: //2218/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x7F61E06B0688, addr=10.10.254.42, port=5060, sentBy_port=0, local_addr=172.16.30.9, is_req=1, transport=1, switch=0, callBack=0x556DD5B7A030 May 6 06:32:24.376: //2218/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 May 6 06:32:24.376: //2218/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 May 6 06:32:24.377: //2218/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately May 6 06:32:24.377: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportLogicSendMsg: connection-reuse configured, listen conn-id : 3 May 6 06:32:24.377: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x7F61E06B0688, addr=10.10.254.42, port=5060, local_addr=172.16.30.9, connId=3 vrfid=0 sig_tos=0x60 for UDP May 6 06:32:24.377: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 37 May 6 06:32:24.377: //2219/000000000000/SIP/Info/verbose/4096/sipSPIUaddccCallIdToTable: Adding call id 8AB to table May 6 06:32:24.377: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 1000, sip_vrfid 0, voice_vrfid 0 May 6 06:32:24.377: //2219/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 May 6 06:32:24.377: //2219/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 May 6 06:32:24.377: //2219/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: sip-ua conn_reuse configured May 6 06:32:24.377: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 172.16.30.9 for SIP May 6 06:32:24.377: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 172.16.30.9 for SIP May 6 06:32:24.377: //2219/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 172.16.30.9 May 6 06:32:24.377: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: bind_inuse: 1conn_reuse: 1 May 6 06:32:24.377: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 172.16.30.9 May 6 06:32:24.377: //2219/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x7F61DF859148 B4C0D1C2-297A11F0-88ACEB9E-95F6367F@172.16.30.9 May 6 06:32:24.377: //2219/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x7F61DF859148 key=B4C0D1C2-297A11F0-88ACEB9E-95F6367F@172.16.30.9 balance 0 May 6 06:32:24.377: //2219/000000000000/SIP/State/sipSPIChangeState: 0x7F61DF859148 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) May 6 06:32:24.378: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x7F61D29BDCF0 with refCount = 1 May 6 06:32:24.378: //2219/000000000000/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 15 event May 6 06:32:24.378: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT May 6 06:32:24.378: //2219/000000000000/SIP/Error/sipSPIAddPrivacyHeader: Orig Container is NULL...should have value except in case of sending OOD Options ping. May 6 06:32:24.378: //2219/000000000000/SIP/Error/sipSPIAddAssertedIDHeader: Orig Container is NULL...should have value except in case of sending OOD Options ping. May 6 06:32:24.378: //2219/000000000000/SIP/Error/sipSPIAddPreferredIDHeader: Orig Container is NULL...should have value except in case of sending OOD Options ping. May 6 06:32:24.378: //2219/000000000000/SIP/Info/info/4096/sipSPISendOptionsRequest: Associated container=0x7F61D7979590 to Options May 6 06:32:24.378: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0 May 6 06:32:24.378: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 1000, sip_vrfid 0, voice_vrfid 0 May 6 06:32:24.378: //2219/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE May 6 06:32:24.378: //2219/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x7F61D29BDCF0, addr=10.10.254.10, port=5060, sentBy_port=0, local_addr=172.16.30.9, is_req=1, transport=1, switch=0, callBack=0x556DD5B7A030 May 6 06:32:24.378: //2219/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 May 6 06:32:24.378: //2219/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 May 6 06:32:24.378: //2219/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately May 6 06:32:24.378: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportLogicSendMsg: connection-reuse configured, listen conn-id : 3 May 6 06:32:24.379: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x7F61D29BDCF0, addr=10.10.254.10, port=5060, local_addr=172.16.30.9, connId=3 vrfid=0 sig_tos=0x60 for UDP May 6 06:32:24.379: //2218/000000000000/SIP/Msg/ccsipDisplayMsg: Sent: OPTIONS sip:10.10.254.42:5060 SIP/2.0 Via: SIP/2.0/UDP 172.16.30.9:5060;branch=z9hG4bK5A41EAF From: ;tag=2CDB08A-7AC To: Date: Tue, 06 May 2025 06:32:24 GMT Call-ID: B4C083AE-297A11F0-88ABEB9E-95F6367F@172.16.30.9 User-Agent: Cisco-SIPGateway/IOS-17.6.1a Max-Forwards: 70 CSeq: 101 OPTIONS Contact: Content-Length: 0 May 6 06:32:24.379: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7F61E06B0688 May 6 06:32:24.379: //2219/000000000000/SIP/Msg/ccsipDisplayMsg: Sent: OPTIONS sip:10.10.254.10:5060 SIP/2.0 Via: SIP/2.0/UDP 172.16.30.9:5060;branch=z9hG4bK5A52317 From: ;tag=2CDB08C-1FCF To: Date: Tue, 06 May 2025 06:32:24 GMT Call-ID: B4C0D1C2-297A11F0-88ACEB9E-95F6367F@172.16.30.9 User-Agent: Cisco-SIPGateway/IOS-17.6.1a Max-Forwards: 70 CSeq: 101 OPTIONS Contact: Content-Length: 0 May 6 06:32:24.379: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7F61D29BDCF0 May 6 06:32:24.382: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x7F61D29BDCF0 with refCount = 1 May 6 06:32:24.382: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x7F61E06B0688 with refCount = 1 May 6 06:32:24.382: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.10.254.10]:5060, local_address:[172.16.30.9] May 6 06:32:24.382: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7F61D29BDCF0 May 6 06:32:24.383: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 May 6 06:32:24.383: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0 May 6 06:32:24.383: //2219/000000000000/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.30.9:5060;branch=z9hG4bK5A52317;received=10.11.84.90;rport=5060 Call-ID: B4C0D1C2-297A11F0-88ACEB9E-95F6367F@172.16.30.9 From: ;tag=2CDB08C-1FCF To: ;tag=yfh575b5 CSeq: 101 OPTIONS Allow: OPTIONS,NOTIFY,SUBSCRIBE,INFO,REGISTER,MESSAGE,REFER,UPDATE,PRACK,BYE,CANCEL,ACK,INVITE Supported: privacy,precondition,100rel Content-Length: 0 May 6 06:32:24.383: //2219/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 May 6 06:32:24.383: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog May 6 06:32:24.383: //2219/000000000000/SIP/Info/info/1024/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK5A52317 from via branch list May 6 06:32:24.383: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x7F61E06B0688) counter, current msg->refCount = 2 May 6 06:32:24.383: //2219/000000000000/SIP/Info/verbose/1024/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX May 6 06:32:24.383: //2219/000000000000/SIP/Info/info/4096/sipSPIHandle_ccsip_api_options_result: Optionsping feature disabled SIP_ADDR_INVALID = FALSE, Response_code = 200, Source = External, PingStatus NOT SAVED in Stack. May 6 06:32:24.383: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_get_ood_optionsPingTimerContext: Timer context not found May 6 06:32:24.383: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_retry_ood_optionsPingTimer: Timer context is NULL here for dial-peer tag 1000 May 6 06:32:24.383: //-1/xxxxxxxxxxxx/SIP/Info/notify/10240/sipSPI_handle_ood_optionsPing_response: SIP dial-peer 1000: state change to active May 6 06:32:24.384: %SIP-5-DIALPEER_STATUS: VoIP dial-Peer <1000> is Up, Raising SNMP UP Trap May 6 06:32:24.384: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_get_ood_optionsPingTimerContext: Timer context not found May 6 06:32:24.384: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_reset_ood_optionsPingTimer: Timer context is NULL for dial-peer tag 1000 May 6 06:32:24.384: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x7F61E06B0688) counter, current msg->refCount = 1 May 6 06:32:24.384: //2219/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteccCallIdFromTable: Removing call id 8AB May 6 06:32:24.384: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContextFromTable: Context for key=[2219] removed. May 6 06:32:24.384: //2219/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x7F61DF859148 key=B4C0D1C2-297A11F0-88ACEB9E-95F6367F@172.16.30.9 May 6 06:32:24.384: //2219/000000000000/SIP/Info/verbose/4096/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd May 6 06:32:24.384: //2219/000000000000/SIP/Error/sipSPIFlushDeferredQueue: Invalid deferredQueue May 6 06:32:24.384: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x7F61DC3EC428, addr=10.10.254.10, port=5060, local_addr=172.16.30.9, unregistering context=0x7F61DF859148 May 6 06:32:24.384: //-1/xxxxxxxxxxxx/SIP/Info/critical/512/sipConnectionManagerUnregisterCtxtInConnection: Could not find conn holder for addr=10.10.254.10 May 6 06:32:24.384: //2219/000000000000/SIP/Transport/sipSPITransportContextCleanup: Could not purge context gcb=0x7F61DF859148 from the connection; gcb might be locked May 6 06:32:24.384: //2219/000000000000/SIP/Error/ws_call_fork_cleanup: ws_info is NULL May 6 06:32:24.384: //2219/000000000000/SIP/Info/verbose/1/sipSPI_ipip_free_codec_profile: Codec Profiles Freed May 6 06:32:24.384: //2219/000000000000/SIP/Info/info/8192/sipSPIStopOverlapInfoTimer: Stopping Overlap Info Timer May 6 06:32:24.385: //-1/xxxxxxxxxxxx/SIP/Error/ws_info_free: ws_info is NULL !!! May 6 06:32:24.385: //2219/000000000000/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Freeing ccb 0x7F61DF859148 May 6 06:32:24.385: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIGetContextFromTable: NO context for key[2219] May 6 06:32:24.385: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7F61E06B0688 May 6 06:32:24.394: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x7F61E06B0688 with refCount = 1 May 6 06:32:24.394: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x7F61D29BDCF0 with refCount = 1 May 6 06:32:24.394: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.10.254.42]:5060, local_address:[172.16.30.9] May 6 06:32:24.394: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7F61E06B0688 May 6 06:32:24.394: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 May 6 06:32:24.394: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0 May 6 06:32:24.394: //2218/000000000000/SIP/Msg/ccsipDisplayMsg: Received: SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.16.30.9:5060;branch=z9hG4bK5A41EAF;received=10.11.84.90;rport=5060 Call-ID: B4C083AE-297A11F0-88ABEB9E-95F6367F@172.16.30.9 From: ;tag=2CDB08A-7AC To: ;tag=jawk5m8k CSeq: 101 OPTIONS Warning: 399 03077.09093.A.005.403.228.0.11.02248.00000000.1075445762 "Invalid User" Content-Length: 0 May 6 06:32:24.395: //2218/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 May 6 06:32:24.395: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog May 6 06:32:24.395: //2218/000000000000/SIP/Info/info/1024/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK5A41EAF from via branch list May 6 06:32:24.395: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x7F61D29BDCF0) counter, current msg->refCount = 2 May 6 06:32:24.395: //2218/000000000000/SIP/Info/verbose/1024/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX May 6 06:32:24.395: //2218/000000000000/SIP/Info/info/4096/sipSPIHandle_ccsip_api_options_result: Optionsping feature disabled SIP_ADDR_INVALID = FALSE, Response_code = 403, Source = External, PingStatus NOT SAVED in Stack. May 6 06:32:24.395: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_get_ood_optionsPingTimerContext: Timer context not found May 6 06:32:24.395: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_reset_ood_optionsPingTimer: Timer context is NULL for dial-peer tag 1000 May 6 06:32:24.395: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x7F61D29BDCF0) counter, current msg->refCount = 1 May 6 06:32:24.395: //2218/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteccCallIdFromTable: Removing call id 8AA May 6 06:32:24.395: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContextFromTable: Context for key=[2218] removed. May 6 06:32:24.395: //2218/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x7F61DF8518F8 key=B4C083AE-297A11F0-88ABEB9E-95F6367F@172.16.30.9 May 6 06:32:24.395: //2218/000000000000/SIP/Info/verbose/4096/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd May 6 06:32:24.395: //2218/000000000000/SIP/Error/sipSPIFlushDeferredQueue: Invalid deferredQueue May 6 06:32:24.396: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x7F61DC3EC428, addr=10.10.254.42, port=5060, local_addr=172.16.30.9, unregistering context=0x7F61DF8518F8 May 6 06:32:24.396: //-1/xxxxxxxxxxxx/SIP/Info/critical/512/sipConnectionManagerUnregisterCtxtInConnection: Could not find conn holder for addr=10.10.254.42 May 6 06:32:24.396: //2218/000000000000/SIP/Transport/sipSPITransportContextCleanup: Could not purge context gcb=0x7F61DF8518F8 from the connection; gcb might be locked May 6 06:32:24.396: //2218/000000000000/SIP/Error/ws_call_fork_cleanup: ws_info is NULL May 6 06:32:24.396: //2218/000000000000/SIP/Info/verbose/1/sipSPI_ipip_free_codec_profile: Codec Profiles Freed May 6 06:32:24.396: //2218/000000000000/SIP/Info/info/8192/sipSPIStopOverlapInfoTimer: Stopping Overlap Info Timer May 6 06:32:24.396: //-1/xxxxxxxxxxxx/SIP/Error/ws_info_free: ws_info is NULL !!! May 6 06:32:24.396: //2218/000000000000/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Freeing ccb 0x7F61DF8518F8 May 6 06:32:24.396: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIGetContextFromTable: NO context for key[2218] May 6 06:32:24.396: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7F61D29BDCF0 May 6 06:32:35.517: //-1/xxxxxxxxxxxx/SIP/Transport/sip_find_connid_by_fd: Map fd 0 to index 4 May 6 06:32:35.517: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x7F61D29BDCF0 with refCount = 1 May 6 06:32:35.518: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x7F61E06B0688 with refCount = 1 May 6 06:32:35.518: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7F61D29BDCF0 May 6 06:32:35.518: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1 May 6 06:32:35.518: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0 May 6 06:32:35.518: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x7F61DC3EC370, remote_addr=10.0.1.12, remote_port=34401, local_addr=10.0.1.250, local_port=5060, connid=4, transport=TCP May 6 06:32:35.518: //-1/xxxxxxxxxxxx/SIP/Info/info/4608/sipHolderGetConnInstance: Return existing connection for port 34401 connId 4 May 6 06:32:35.519: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: OPTIONS sip:10.0.1.250:5060 SIP/2.0 Via: SIP/2.0/TCP 10.0.1.12:5060;branch=z9hG4bK1acf7174af1b6c From: ;tag=332686128 To: Date: Tue, 06 May 2025 06:32:35 GMT Call-ID: e4478900-1f114846-19d0b9-c01000a@10.0.1.12 User-Agent: Cisco-CUCM14.0 CSeq: 101 OPTIONS Contact: Max-Forwards: 0 Content-Length: 0 May 6 06:32:35.519: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIIpTrustSilentDiscard: sipSPIIpTrustSilentDiscard: called for method [101] May 6 06:32:35.519: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x7F61DF8518F8) with key=[2220] to table May 6 06:32:35.519: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init: May 6 06:32:35.519: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init: May 6 06:32:35.519: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised.. May 6 06:32:35.519: //-1/000000000000/SIP/Info/verbose/4097/ccsip_platform_init_ccb: Initialising rtp session queue May 6 06:32:35.519: //-1/000000000000/SIP/Info/info/16384/sipSPICheckIpip: User portion null/non-e164.. DP match skipped May 6 06:32:35.520: //-1/000000000000/SIP/Info/info/2048/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done May 6 06:32:35.520: //-1/000000000000/SIP/Info/info/4096/sipSPISetCallingInfo: calling host comes from From: 10.0.1.12 May 6 06:32:35.520: //-1/000000000000/SIP/Info/verbose/4096/sipSPIUpdateCallingInfoUsingRpidOrFrom: Updating Calling Info with FROM header data May 6 06:32:35.520: //-1/000000000000/SIP/Info/info/2048/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done May 6 06:32:35.520: //-1/000000000000/SIP/Info/verbose/1024/sipSPIGetViaHostInURLFormat: VIA URL:sip:10.0.1.12:5060, Host:10.0.1.12 May 6 06:32:35.520: //-1/000000000000/SIP/Info/verbose/67584/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : May 6 06:32:35.521: //-1/000000000000/SIP/Error/sipSPIGetPeerByCalledPartyId: input arg error May 6 06:32:35.521: //-1/000000000000/SIP/Info/critical/10240/sipSPIGetCallConfig: No match found for P-Called-Party-ID May 6 06:32:35.521: //-1/000000000000/SIP/Error/sipSPIUpdateCallInfo: input argument error May 6 06:32:35.521: //-1/xxxxxxxxxxxx/SIP/Info/verbose/64/ccsip_inbound_profile_populate_callinfo_in_ccb: Dial-peer 2000 is used for inbound profiles config May 6 06:32:35.521: //-1/xxxxxxxxxxxx/SIP/Info/info/64/sipSPISetSipProfilesTag: voice class SIPProfiles tag is set : 10 May 6 06:32:35.521: //-1/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 May 6 06:32:35.521: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor: Checking Invite Dialog May 6 06:32:35.521: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIIpTrustSilentDiscard: sipSPIIpTrustSilentDiscard: called for method [101] May 6 06:32:35.521: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.0.1.12,Port 34401, Transport 2, SentBy Port 5060vrfid 0 May 6 06:32:35.522: //-1/000000000000/SIP/Info/verbose/4608/sipSPISipIncomingMsg: copy the natted transport info to ccb natted dest: 10.0.1.12:34401,natted src: 10.0.1.250:5060, natted transport: 2 May 6 06:32:35.522: //-1/000000000000/SIP/Info/info/1024/sipSPISipIncomingMsg: sip via host 10.0.1.12 May 6 06:32:35.522: //-1/000000000000/SIP/Info/info/9216/sipSPISipIncomingMsg: sip nat auto detect 0 May 6 06:32:35.522: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 0, sip_vrfid 0, voice_vrfid 0 May 6 06:32:35.522: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 May 6 06:32:35.522: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 May 6 06:32:35.522: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: sip-ua conn_reuse configured May 6 06:32:35.522: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 172.16.30.9 for SIP May 6 06:32:35.522: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 172.16.30.9 for SIP May 6 06:32:35.523: //-1/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 172.16.30.9 May 6 06:32:35.523: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: bind_inuse: 1conn_reuse: 1 May 6 06:32:35.523: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 172.16.30.9 May 6 06:32:35.523: //-1/BB658FEF88AD/SIP/State/sipSPIChangeState: 0x7F61DF8518F8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE) May 6 06:32:35.523: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.0.1.12,Port 34401, Transport 2, SentBy Port 5060vrfid 0 May 6 06:32:35.523: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT May 6 06:32:35.523: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 10.0.1.12,Port 34401, Transport 2, SentBy Port 5060vrfid 0 May 6 06:32:35.523: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_lock: Increment msg (0x7F61E06B0688) counter, current msg->refCount = 2 May 6 06:32:35.524: //-1/xxxxxxxxxxxx/SIP/Error/httpish_msg_free: Freeing NULL pointer! May 6 06:32:35.524: //2220/BB658FEF88AD/SIP/Info/verbose/1024/sipSPIGetViaHostInURLFormat: VIA URL:sip:10.0.1.12:5060, Host:10.0.1.12 May 6 06:32:35.524: //2220/BB658FEF88AD/SIP/Info/verbose/67584/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : May 6 06:32:35.524: //2220/BB658FEF88AD/SIP/Error/sipSPIGetPeerByCalledPartyId: input arg error May 6 06:32:35.524: //2220/BB658FEF88AD/SIP/Info/critical/10240/sipSPIGetCallConfig: No match found for P-Called-Party-ID May 6 06:32:35.524: //2220/BB658FEF88AD/SIP/Error/sipSPIUpdateCallInfo: input argument error May 6 06:32:35.524: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 2000, sip_vrfid 0, voice_vrfid 0 May 6 06:32:35.525: //2220/BB658FEF88AD/SIP/Info/notify/131072/sipSPIGetCallConfig: peer_tag = 2000, tenant_tag = 0, VRFId = 0 May 6 06:32:35.525: //2220/BB658FEF88AD/SIP/Info/info/2048/sipSPIGetCallConfig: Peer tag 2000 matched for incoming call May 6 06:32:35.525: //2220/BB658FEF88AD/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header May 6 06:32:35.525: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 2000, sip_vrfid 0, voice_vrfid 0 May 6 06:32:35.525: //2220/BB658FEF88AD/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 May 6 06:32:35.525: //2220/BB658FEF88AD/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 May 6 06:32:35.525: //2220/BB658FEF88AD/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: sip-ua conn_reuse configured May 6 06:32:35.525: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.0.1.250 for SIP May 6 06:32:35.525: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.0.1.250 for SIP May 6 06:32:35.525: //2220/BB658FEF88AD/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.0.1.250 May 6 06:32:35.525: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: bind_inuse: 1conn_reuse: 1 May 6 06:32:35.525: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.0.1.250 May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/2048/sipSPISetAudioForcedConfig: audio forced config is set to FALSE May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/verbose/2048/sipSPIGetCallConfig: Media Antitrombone disabled May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder high-density disabled May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/8704/sipSPIGetCallConfig: Incoming: No Defer BYE for last call stats May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/1/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: STUN Usage is not enabled May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/verbose/12288/sipSPIGetModemInfoPerCall: peer_callID=0 May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/critical/32768/ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg.. May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/8704/sipSPIGetCallConfig: Incoming: No defer BYE for last call stats May 6 06:32:35.526: //-1/xxxxxxxxxxxx/SIP/Error/ccsip_websocket_forking_enabled_in_any_dial_peer: Media profile stream-service not configured under any dial-peer or media-class May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: en_p->encap_s.voIP.voipPeerCfgMediaClass = 0 May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer has no media class recorder. May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/32768/ccsip_ipip_media_forking_intra_frame_request_config: MF: FIR en_p->encap_s.voIP.voipPeerCfgMediaClass = 0 May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/info/32768/ccsip_ipip_media_forking_get_forked_leg_config: MF: This leg is not forked call leg. May 6 06:32:35.526: //2220/BB658FEF88AD/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp configure for this leg. May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/info/8192/sipSPIGetCallConfig: Media forking disabled May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/critical/11264/ccsipInitDSCPPolicyInfo: No DSCP Profile configured, No RPH 2 DSCP Mapping and DSCP policing May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/verbose/8192/sipSPIGetCallConfig: Initilise the DSCP policy May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/verbose/8192/sipSPICheckFAAnatAssymetricOrDO2EO: Not a SIP-SIP call or not in FA mode May 6 06:32:35.527: //-1/xxxxxxxxxxxx/SIP/Info/info/64/sipSPISetSipProfilesTag: voice class SIPProfiles tag is set : 10 May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/notify/2049/populate_vcc_data: Using Voice Class Codec, tag = 1 and offer-all is = FALSE May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/notify/8192/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/verbose/10240/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0 May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/verbose/2048/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0 May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/notify/10240/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled May 6 06:32:35.527: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Decrement msg (0x7F61E06B0688) counter, current msg->refCount = 1 May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/verbose/6144/addAllowHeaderKpml: KPML Subscriptions allowed. May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1 May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: peer_tag=2000 May 6 06:32:35.527: //2220/BB658FEF88AD/SIP/Info/info/2048/resolve_media_ip_address_to_bind: Configuration not found for bind media source-ip May 6 06:32:35.528: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 2000, sip_vrfid 0, voice_vrfid 0 May 6 06:32:35.528: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_media_ip_address_to_bind: VRF id = 0 May 6 06:32:35.528: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.0.1.250 for SIP May 6 06:32:35.528: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.0.1.250 for SIP May 6 06:32:35.528: //2220/BB658FEF88AD/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.0.1.250 May 6 06:32:35.528: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 2000, sip_vrfid 0, voice_vrfid 0 May 6 06:32:35.528: //2220/BB658FEF88AD/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 May 6 06:32:35.528: //2220/BB658FEF88AD/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0 May 6 06:32:35.528: //2220/BB658FEF88AD/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: sip-ua conn_reuse configured May 6 06:32:35.528: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.0.1.250 for SIP May 6 06:32:35.528: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.0.1.250 for SIP May 6 06:32:35.528: //2220/BB658FEF88AD/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.0.1.250 May 6 06:32:35.528: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: bind_inuse: 1conn_reuse: 1 May 6 06:32:35.528: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.0.1.250 May 6 06:32:35.528: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_OPTIONS_RESP May 6 06:32:35.528: //2220/BB658FEF88AD/SIP/Info/info/4096/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS May 6 06:32:35.529: //2220/BB658FEF88AD/SIP/State/sipSPIChangeState: 0x7F61DF8518F8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE) May 6 06:32:35.529: //2220/BB658FEF88AD/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x7F61DF8518F8 key=e4478900-1f114846-19d0b9-c01000a@10.0.1.12 balance 1 May 6 06:32:35.529: //2220/BB658FEF88AD/SIP/Info/verbose/4096/sipSPIUaddccCallIdToTable: Adding call id 8AC to table May 6 06:32:35.529: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 38 May 6 06:32:35.529: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x7F61D29BDCF0 with refCount = 1 May 6 06:32:35.529: //2220/BB658FEF88AD/SIP/Info/info/4096/sipSPISendOptionsResponse: Associated container=0x7F61D797D760 to Options Response May 6 06:32:35.529: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 161 May 6 06:32:35.529: //2220/BB658FEF88AD/SIP/Transport/sipSPITransportSendMessage: msg=0x7F61D29BDCF0, addr=10.0.1.12, port=34401, sentBy_port=5060, local_addr=10.0.1.250, is_req=0, transport=2, switch=0, callBack=0x556DD5B7A080 May 6 06:32:35.529: //2220/BB658FEF88AD/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1 May 6 06:32:35.529: //2220/BB658FEF88AD/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately May 6 06:32:35.529: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x7F61D29BDCF0, addr=10.0.1.12, port=34401, local_addr=10.0.1.250, connId=4 vrfid=0, sig_tos=0x60 for TCP May 6 06:32:35.529: //2220/BB658FEF88AD/SIP/Info/verbose/4096/sipSPIUdeleteccCallIdFromTable: Removing call id 8AC May 6 06:32:35.529: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContextFromTable: Context for key=[2220] removed. May 6 06:32:35.530: //2220/BB658FEF88AD/SIP/Info/verbose/4096/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x7F61DF8518F8 key=e4478900-1f114846-19d0b9-c01000a@10.0.1.12 May 6 06:32:35.530: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7F61E06B0688 May 6 06:32:35.530: //2220/BB658FEF88AD/SIP/Info/verbose/4096/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd May 6 06:32:35.530: //2220/BB658FEF88AD/SIP/Error/sipSPIFlushDeferredQueue: Invalid deferredQueue May 6 06:32:35.530: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x7F61DC3EC370, addr=10.0.1.12, port=34401, local_addr=10.0.1.250, unregistering context=0x7F61DF8518F8 May 6 06:32:35.530: //2220/BB658FEF88AD/SIP/Transport/sipSPITransportContextCleanup: Could not purge context gcb=0x7F61DF8518F8 from the connection; gcb might be locked May 6 06:32:35.530: //2220/BB658FEF88AD/SIP/Error/ws_call_fork_cleanup: ws_info is NULL May 6 06:32:35.530: //2220/BB658FEF88AD/SIP/Info/verbose/1/sipSPI_ipip_free_codec_profile: Codec Profiles Freed May 6 06:32:35.530: //2220/BB658FEF88AD/SIP/Info/info/8192/sipSPIStopOverlapInfoTimer: Stopping Overlap Info Timer May 6 06:32:35.530: //-1/xxxxxxxxxxxx/SIP/Error/ws_info_free: ws_info is NULL !!! May 6 06:32:35.530: //2220/BB658FEF88AD/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Freeing ccb 0x7F61DF8518F8 May 6 06:32:35.530: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIGetContextFromTable: NO context for key[2220] May 6 06:32:35.530: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPITransportSendMessage: gcb has cleanedup, Done with send operations for this context May 6 06:32:35.530: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIGetContextFromTable: NO context for key[2220] May 6 06:32:35.531: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_tcp_queue_event: Event type: send msg, connid: 4, fd: 0 May 6 06:32:35.531: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/TCP 10.0.1.12:5060;branch=z9hG4bK1acf7174af1b6c From: ;tag=332686128 To: ;tag=2CDDC16-D9D Date: Tue, 06 May 2025 06:32:35 GMT Call-ID: e4478900-1f114846-19d0b9-c01000a@10.0.1.12 Server: Cisco-SIPGateway/IOS-17.6.1a CSeq: 101 OPTIONS Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: kpml, telephone-event Accept: application/sdp Supported: 100rel,timer,resource-priority,replaces,sdp-anat Content-Type: application/sdp Content-Length: 161 v=0 o=CiscoSystemsSIP-GW-UserAgent 3698 57 IN IP4 10.0.1.250 s=SIP Call c=IN IP4 10.0.1.250 t=0 0 m=audio 0 RTP/AVP 18 0 8 9 4 2 15 3 c=IN IP4 10.0.1.250 May 6 06:32:35.532: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7F61D29BDCF0 LTB1-RACK4-RTRGATEWAY#