[cisco-voip] SIP OPTIONS pings are blocked on Cisco CUBE 3945E - Resource failure, dropping OPTIONS

Anthony Holloway avholloway+cisco-voip at gmail.com
Tue Oct 9 14:58:09 EDT 2018 

OPTIONS does not have to match a dial peer to work.  However, if you are
going to match a dial peer at all, it would likely be for the express
purpose of replying from the correct interface, if you have more than one
potential interfaces, and you for some reason cannot bind globally.  Thus
using the correct bind statement on a dial-peer for OPTIONS reply, would be
necessary.  In which case, you would need to match an incoming call leg
dial peer by the SIP Via header alone, and not, say for example, incoming
called number.

Example Pseudo Configuration:

voice class sip uri 100
 host ipv4:10.1.1.1
!
dial-peer voice 100 voip
 incoming uri via 100
 bind media interface g0/1
 bind control interface g0/1
!

On Tue, Oct 9, 2018 at 1:12 PM Maciej Bylica <mbgatherer at gmail.com> wrote:

> Thanks for prompt answer.
>
> No, i am not using CCP.
> As i see OPTIONS ping does not match with any dialpeer
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/1024/ccsipInitPldCallingInfo: non-numeric
> calling number: *stringhere*
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetViaHostInURLFormat: VIA
> URL:sip:10.10.10.10:5060, Host:100.64.4.31
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/verbose/67584/sipSPIGetShrlPeer: Try match
> incoming dialpeer for Calling number: : *stringhere*
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Error/sipSPIGetPeerByCalledPartyId:
>
>  input arg error
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/critical/10240/sipSPIGetCallConfig: No match
> found for P-Called-Party-ID
>
> Oct  9 17:50:04.068: //3652/95FFAA748E45/SIP/Error/sipSPIUpdateCallInfo:
>
>  input argument error
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition
> tag absent in Require/Supported header
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/verbose/2048/sipSPIGetCallConfig: Media
> Antitrombone disabled
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the
> configured mode as FLOW-THROUGH
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder
> high-density disabled
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode
> set to FLOW_THROUGH
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: Non dial peer
> leg - using RTP Supported Codecs
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
> Codecs supported by GW 18
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
> Codecs supported by GW 0
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
> Codecs supported by GW 8
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
> Codecs supported by GW 9
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
> Codecs supported by GW 4
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
> Codecs supported by GW 2
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
> Codecs supported by GW 15
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
> Codecs supported by GW 255
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/critical/32768/ccsip_ipip_media_forking_update_preferred_codec:
> MF: Not a Forked SIP leg..
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp
> configure for this leg.
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/verbose/12288/sipSPIGetModemInfoPerCall:
> peer_callID=0
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Error/ccsip_ipip_media_forking_anchor_leg_config:
>
>  MF: *Dial-peer is absent*..
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state
> = 0 & New state = -1
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Info/info/32768/ccsip_ipip_media_forking_anchor_leg_reset:
> MF: Anchor leg config reset done...
>
> Oct  9 17:50:04.068:
> //3652/95FFAA748E45/SIP/Error/ccsip_ipip_media_forking_intra_frame_request_config:
>
>
>  MF:video profile Dial-peer is absent..
>
>
> OPTIONS looks like following:
>
> OPTIONS sip:domain.name.here:5060 SIP/2.0
>
> From: <sip:*stringhere*@domain.name.here>;tag=4a6000292f6a
>
> To: <sip:*stringhere*@domain.name.here>
>
>
>
> I do not have any script in use there, the configuration in pretty basic.
> What i have found is that second OPTIONS (the one that is left/dropped
> without OK) also generates following output:
>
> Oct  9 17:50:38.070:
> //-1/xxxxxxxxxxxx/SIP/Info/verbose/4096/ccsip_new_msg_preprocessor:
> Checking Invite Dialog
>
> Oct  9 17:50:38.070:
> //3653/9862338A8E46/SIP/Info/verbose/4096/sipSPIFindCcbUASReqTable:
> *****CCB found in UAS Request table. ccb=0x2766B958
>
> Oct  9 17:50:38.070:
> //3653/9862338A8E46/SIP/Info/info/4096/sipSPICheckFromToRequest: Trying
> with child CCB 0x0 index 0 curr_child 0
>
>
> Oct  9 17:50:38.070:
> //3653/9862338A8E46/SIP/Error/sipSPICheckFromToRequest:
>
>
>
> Failed FROM/TO Request check - IGNORE IF HAIRPIN CALL
>
> old_from: <sip:*stringhere*@domain.name.here>;tag=4a6000292f6a
>
> old_to: <sip:*stringhere*@domain.name.here>;tag=D7E844-1438
>
> new_from: <sip:*stringhere*@domain.name.here>;tag=6c7f09452671
>
> new_to: <sip:*stringhere*@domain.name.here>
>
> ....
>
> Oct  9 17:50:04.068: //-1/xxxxxxxxxxxx/SIP/Error/httpish_msg_free:
>
>  Freeing NULL pointer!
>
> Could you please point me where i can find some information how to create
> such dial-peer for OPTIONS or give me a brief example of this configuration
> please.
>
> Thanks
> Maciej.
>
>
>
>
> wt., 9 paź 2018 o 16:39 Nick Barnett <nicksbarnett at gmail.com> napisał(a):
>
>> Are you using Customer Call Back? Which dial peer is the options ping
>> hitting? Does that dial peer have the CCB script on it? If so... maybe make
>> another dial peer for options pings that does not have the script enabled.
>> This is just a hunch...
>>
>> On Tue, Oct 9, 2018 at 6:50 AM Maciej Bylica <mbgatherer at gmail.com>
>> wrote:
>>
>>> Hi
>>>
>>> I have really strange problem with SIP OPTIONS pings.
>>> The Cisco i have (CUBE 3945 ios Version 15.3(3)M5) responds only to the
>>> first OPTIONS packet that is received from the endpoint.
>>> The rest of OPTIONs are dropped with following debug output:
>>>
>>> Oct  9 12:52:06 10.10.10.10 8694907: Oct  9 10:55:58.194:
>>> //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI :
>>> SIPSPI_EV_CC_OPTIONS_RESP
>>> Oct  9 12:52:06 10.10.10.10 8694908: Oct  9 10:55:58.194:
>>> //148025/BCB3C79A92C0/SIP/Info/info/4096/sact_idle_new_message_options:
>>> ccsip_api_options_ind returned: SIP_SUCCESS
>>> Oct  9 12:52:06 10.10.10.10 8694909: Oct  9 10:55:58.194:
>>> //148025/BCB3C79A92C0/SIP/State/sipSPIChangeState: 0x258D7210 : State
>>> change from (STATE_IDLE, SUBSTATE_NONE)  to (SIP_STATE_OPTIONS_WAIT,
>>> SUBSTATE_NONE)
>>> Oct  9 12:52:06 10.10.10.10 8694910: Oct  9 10:55:58.194:
>>> //148025/BCB3C79A92C0/SIP/Error/sipSPIUaddCcbToTable:
>>> Oct  9 12:52:06 10.10.10.10 8694911:  *Could not add ccb to table*.
>>> ccb=0x258D7210
>>> key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
>>> Oct  9 12:52:06 10.10.10.10 8694912: Oct  9 10:55:58.194:
>>> //148025/BCB3C79A92C0/SIP/Error/sact_idle_new_message_options:
>>> Oct  9 12:52:06 10.10.10.10 8694913:  *Resource failure, dropping
>>> OPTIONS*
>>>
>>> The true is that Cisco receives quite significant amount of SIP OPTIONs
>>> from the endpoint in short time, like 10 OPTIONS packeges within
>>> miliseconds.
>>> The after-effect i want to achieve is a response for each incoming
>>> OPTIONS
>>>
>>> Example of a successful response:
>>> Oct  9 11:30:37 10.10.10.10 8625106: Oct  9 09:34:28.569:
>>> //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI :
>>> SIPSPI_EV_CC_OPTIONS_RESP
>>> Oct  9 11:30:37 10.10.10.10 8625107: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/Info/info/4096/sact_idle_new_message_options:
>>> ccsip_api_options_ind returned: SIP_SUCCESS
>>> Oct  9 11:30:37 10.10.10.10 8625108: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/State/sipSPIChangeState: 0x258B1110 : State
>>> change from (STATE_IDLE, SUBSTATE_NONE)  to (SIP_STATE_OPTIONS_WAIT,
>>> SUBSTATE_NONE)
>>> Oct  9 11:30:37 10.10.10.10 8625109: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to
>>> table. ccb=0x258B1110
>>> key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3 balance
>>> 1
>>> Oct  9 11:30:37 10.10.10.10 8625110: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/Info/verbose/4096/sipSPIUaddccCallIdToTable:
>>> Adding call id 23DA9 to table
>>> Oct  9 11:30:37 10.10.10.10 8625111: Oct  9 09:34:28.569:
>>> //-1/xxxxxxxxxxxx/SIP/Info/info/4096/ccsip_process_sipspi_queue_event:
>>> ccsip_spi_get_msg_type returned: 3 for event 38
>>> Oct  9 11:30:37 10.10.10.10 8625112: Oct  9 09:34:28.569:
>>> //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created
>>> msg=0x203FFDA4 with refCount = 1
>>> Oct  9 11:30:37 10.10.10.10 8625113: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/Info/info/4096/sipSPISendOptionsResponse:
>>> Associated container=0x2673A528 to Options Response
>>> Oct  9 11:30:37 10.10.10.10 8625114: Oct  9 09:34:28.569:
>>> //-1/xxxxxxxxxxxx/SIP/Info/verbose/8192/sipSPIAppHandleContainerBody:
>>> sipSPIAppHandleContainerBody len 164
>>> Oct  9 11:30:37 10.10.10.10 8625115: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/Transport/sipSPITransportSendMessage:
>>> msg=0x203FFDA4, addr=11.11.11.11, port=5060, sentBy_port=5060, local_addr=,
>>> is_req=0, transport=1, switch=0, callBack=0x4F48054
>>> Oct  9 11:30:37 10.10.10.10 8625116: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP
>>> extension config:1, check sys cfg:1
>>> Oct  9 11:30:37 10.10.10.10 8625117: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/Transport/sipSPITransportSendMessage: Proceedable
>>> for sending msg immediately
>>> Oct  9 11:30:37 10.10.10.10 8625118: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Trying to
>>> send resp=0x203FFDA4 to default port=5060
>>> Oct  9 11:30:37 10.10.10.10 8625119: Oct  9 09:34:28.569:
>>> //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection:
>>> connection required for raddr:11.11.11.11, rport:5060 with laddr:
>>> Oct  9 11:30:37 10.10.10.10 8625120: Oct  9 09:34:28.569:
>>> //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering
>>> gcb=0x258B1110 with connection=0x2426673C context list
>>> Oct  9 11:30:37 10.10.10.10 8625121: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Connection
>>> obtained...sending msg=0x203FFDA4
>>> Oct  9 11:30:37 10.10.10.10 8625122: Oct  9 09:34:28.569:
>>> //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send
>>> for msg=0x203FFDA4, addr=11.11.11.11, port=5060, local_addr=, connId=2 for
>>> UDP
>>> Oct  9 11:30:37 10.10.10.10 8625123: Oct  9 09:34:28.569:
>>> //146857/5A42A0608E30/SIP/Msg/ccsipDisplayMsg:
>>> Oct  9 11:30:37 10.10.10.10 8625124: Sent:
>>> Oct  9 11:30:37 10.10.10.10 8625125: SIP/2.0 200 OK#015
>>>
>>> Could someone help me with this? I really appreciate your advice.
>>>
>>> Maciej
>>> _______________________________________________
>>> cisco-voip mailing list
>>> cisco-voip at puck.nether.net
>>> https://puck.nether.net/mailman/listinfo/cisco-voip
>>>
>> _______________________________________________
> cisco-voip mailing list
> cisco-voip at puck.nether.net
> https://puck.nether.net/mailman/listinfo/cisco-voip
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20181009/ee9dda00/attachment.html>

More information about the cisco-voip mailing list