We've experienced an issue where the options ping failed and the dial-peer busied out. The issue is cleared before we can raise a TAC ticket. Could someone please assist in interpreting the logs I've collected?
Source: 10.2.170.243
Destination: 10.7.75.30
Aug 10 15:46:38.374: //15404825/000000000000/SIP/Info/info/4096/sipSPIHandle_ccsip_api_options_result: Optionsping feature disabled SIP_ADDR_INVALID = FALSE, Response_code = 408, Source = Internal, PingStatus NOT SAVED in Stack.
Does this mean that it timed out internally and the router didn't send the options ping message?
Aug 10 15:46:37.872: //-1/000000000000/SIP/Info/info/4096/ccsip_ipip_media_service_init:
Aug 10 15:46:37.872: //-1/000000000000/SIP/Info/info/4096/ccsip_tdmip_media_service_init:
Aug 10 15:46:37.872: //-1/000000000000/SIP/Info/verbose/36864/ccsip_ipip_media_forking_init: MF: Queue is initialised..
Aug 10 15:46:37.872: //-1/000000000000/SIP/Info/verbose/4097/ccsip_platform_init_ccb: Initialising rtp session queue
Aug 10 15:46:37.872: //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 37
Aug 10 15:46:37.872: //15404825/000000000000/SIP/Info/verbose/4096/sipSPIUaddccCallIdToTable: Adding call id EB0F19 to table
Aug 10 15:46:37.872: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 206, sip_vrfid 0, voice_vrfid 0
Aug 10 15:46:37.872: //15404825/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0
Aug 10 15:46:37.872: //15404825/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0
Aug 10 15:46:37.872: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 10.2.170.243 for SIP
Aug 10 15:46:37.872: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 10.2.170.243 for SIP
Aug 10 15:46:37.872: //15404825/000000000000/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : 10.2.170.243
Aug 10 15:46:37.872: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr 10.2.170.243
Aug 10 15:46:37.872: //15404825/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToUACTable: ****Adding to UAC table.0x7F0B80960800 744B7901-17FA11ED-866B9F86-8D8AF81D@10.2.170.243
Aug 10 15:46:37.873: //15404825/000000000000/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to table. ccb=0x7F0B80960800 key=744B7901-17FA11ED-866B9F86-8D8AF81D@10.2.170.243 balance 0
Aug 10 15:46:37.873: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created msg=0x7F0B8B23AA88 with refCount = 1
Aug 10 15:46:37.873: //15404825/000000000000/SIP/Info/verbose/8192/sipSPIPresendProcessing: Presend Processing called for 15 event
Aug 10 15:46:37.873: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPISetDateHeader: Converting TimeZone EST to SIP default timezone = GMT
Aug 10 15:46:37.873: //15404825/000000000000/SIP/Info/info/4096/sipSPISendOptionsRequest: Associated container=0x7F0B705A8A08 to Options
Aug 10 15:46:37.873: //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody: sipSPIAppHandleContainerBody len 0
Aug 10 15:46:37.873: //-1/xxxxxxxxxxxx/SIP/Info/verbose/512/ccsip_get_vrf_from_sip_bind: vrfid 0 for tag 206, sip_vrfid 0, voice_vrfid 0
Aug 10 15:46:37.873: //15404825/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE
Aug 10 15:46:37.873: //15404825/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x7F0B8B23AA88, addr=10.7.75.30, port=5060, sentBy_port=0, local_addr=10.2.170.243, is_req=1, transport=1, switch=0, callBack=0x561F6C3E2370
Aug 10 15:46:37.873: //15404825/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
Aug 10 15:46:37.873: //15404825/000000000000/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
Aug 10 15:46:37.873: //15404825/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
Aug 10 15:46:37.873: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportLogicSendMsg: connection-reuse configured, listen conn-id : 2
Aug 10 15:46:37.874: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x7F0B8B23AA88, addr=10.7.75.30, port=5060, local_addr=10.2.170.243, connId=2 vrfid=0 for UDP
Aug 10 15:46:37.874: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7F0B8B23AA88
Aug 10 15:46:37.957: //15404824/000000000000/SIP/Info/info/4096/sipSPIHandle_ccsip_api_options_result: Optionsping feature disabled SIP_ADDR_INVALID = FALSE, Response_code = 408, Source = Internal, PingStatus NOT SAVED in Stack.
Aug 10 15:46:37.957: //15404824/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteccCallIdFromTable: Removing call id EB0F18
Aug 10 15:46:37.957: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContextFromTable: Context for key=[15452102] removed.
Aug 10 15:46:37.957: //15404824/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x7F0B809B1480 key=740BFFD4-17FA11ED-866A9F86-8D8AF81D@10.2.170.243
Aug 10 15:46:37.957: //15404824/000000000000/SIP/Info/verbose/4096/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
Aug 10 15:46:37.957: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x7F0B793BEC70, addr=10.7.75.30, port=5060, local_addr=10.2.170.243, unregistering context=0x7F0B809B1480
Aug 10 15:46:37.958: //-1/xxxxxxxxxxxx/SIP/Info/critical/512/sipConnectionManagerUnregisterCtxtInConnection: Could not find conn holder for addr=10.7.75.30
Aug 10 15:46:37.958: //15404824/000000000000/SIP/Transport/sipSPITransportContextCleanup: Could not purge context gcb=0x7F0B809B1480 from the connection; gcb might be locked
Aug 10 15:46:37.958: //15404824/000000000000/SIP/Info/verbose/1/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
Aug 10 15:46:37.958: //15404824/000000000000/SIP/Info/info/8192/sipSPIStopOverlapInfoTimer: Stopping Overlap Info Timer
Aug 10 15:46:37.958: //15404824/000000000000/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Freeing ccb 0x7F0B809B1480
Aug 10 15:46:38.374: //15404825/000000000000/SIP/Info/info/4096/sipSPIHandle_ccsip_api_options_result: Optionsping feature disabled SIP_ADDR_INVALID = FALSE, Response_code = 408, Source = Internal, PingStatus NOT SAVED in Stack.
Aug 10 15:46:38.374: //15404825/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteccCallIdFromTable: Removing call id EB0F19
Aug 10 15:46:38.374: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIDeleteContextFromTable: Context for key=[15452103] removed.
Aug 10 15:46:38.374: //15404825/000000000000/SIP/Info/verbose/4096/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x7F0B80960800 key=744B7901-17FA11ED-866B9F86-8D8AF81D@10.2.170.243
Aug 10 15:46:38.374: //15404825/000000000000/SIP/Info/verbose/4096/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
Aug 10 15:46:38.374: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerUnregisterCtxtInConnection: gConnTab=0x7F0B793BEC70, addr=10.7.75.30, port=5060, local_addr=10.2.170.243, unregistering context=0x7F0B80960800
Aug 10 15:46:38.374: //-1/xxxxxxxxxxxx/SIP/Info/critical/512/sipConnectionManagerUnregisterCtxtInConnection: Could not find conn holder for addr=10.7.75.30
Aug 10 15:46:38.374: //15404825/000000000000/SIP/Transport/sipSPITransportContextCleanup: Could not purge context gcb=0x7F0B80960800 from the connection; gcb might be locked
Aug 10 15:46:38.374: //15404825/000000000000/SIP/Info/verbose/1/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
Aug 10 15:46:38.374: //15404825/000000000000/SIP/Info/info/8192/sipSPIStopOverlapInfoTimer: Stopping Overlap Info Timer
Aug 10 15:46:38.374: //15404825/000000000000/SIP/Info/verbose/4096/sipSPIUfreeOneCCB: Freeing ccb 0x7F0B80960800
Aug 10 15:46:39.734: //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/sipSPIAddContextToTable: Added context(0x7F0B80960800) with key=[15452104] to table
