Discussion:
[cisco-voip] SIP OPTIONS pings are blocked on Cisco CUBE 3945E - Resource failure, dropping OPTIONS
Maciej Bylica
2018-10-09 11:49:22 UTC
Permalink
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
Nick Barnett
2018-10-09 14:39:36 UTC
Permalink
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...
Post by Maciej Bylica
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.
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//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 8694911: *Could not add ccb to table*.
ccb=0x258D7210
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
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
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//146857/5A42A0608E30/SIP/State/sipSPIChangeState: 0x258B1110 : State
change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT,
SUBSTATE_NONE)
//146857/5A42A0608E30/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to
table. ccb=0x258B1110
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3 balance
1
Adding call id 23DA9 to table
ccsip_spi_get_msg_type returned: 3 for event 38
//-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created
msg=0x203FFDA4 with refCount = 1
Associated container=0x2673A528 to Options Response
sipSPIAppHandleContainerBody len 164
msg=0x203FFDA4, addr=11.11.11.11, port=5060, sentBy_port=5060, local_addr=,
is_req=0, transport=1, switch=0, callBack=0x4F48054
//146857/5A42A0608E30/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP
extension config:1, check sys cfg:1
//146857/5A42A0608E30/SIP/Transport/sipSPITransportSendMessage: Proceedable
for sending msg immediately
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Trying to
send resp=0x203FFDA4 to default port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering
gcb=0x258B1110 with connection=0x2426673C context list
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Connection
obtained...sending msg=0x203FFDA4
//-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 8625125: SIP/2.0 200 OK#015
Could someone help me with this? I really appreciate your advice.
Maciej
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
Maciej Bylica
2018-10-09 18:11:18 UTC
Permalink
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.
Post by Nick Barnett
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...
Post by Maciej Bylica
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.
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//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 8694911: *Could not add ccb to table*.
ccb=0x258D7210
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
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
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//146857/5A42A0608E30/SIP/State/sipSPIChangeState: 0x258B1110 : State
change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT,
SUBSTATE_NONE)
//146857/5A42A0608E30/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to
table. ccb=0x258B1110
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3 balance
1
Adding call id 23DA9 to table
ccsip_spi_get_msg_type returned: 3 for event 38
//-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created
msg=0x203FFDA4 with refCount = 1
Associated container=0x2673A528 to Options Response
sipSPIAppHandleContainerBody len 164
msg=0x203FFDA4, addr=11.11.11.11, port=5060, sentBy_port=5060, local_addr=,
is_req=0, transport=1, switch=0, callBack=0x4F48054
//146857/5A42A0608E30/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP
extension config:1, check sys cfg:1
//146857/5A42A0608E30/SIP/Transport/sipSPITransportSendMessage: Proceedable
for sending msg immediately
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Trying to
send resp=0x203FFDA4 to default port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering
gcb=0x258B1110 with connection=0x2426673C context list
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Connection
obtained...sending msg=0x203FFDA4
//-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 8625125: SIP/2.0 200 OK#015
Could someone help me with this? I really appreciate your advice.
Maciej
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
Maciej Bylica
2018-10-09 20:54:16 UTC
Permalink
Thanks, i am about to modify the config to check.

Many thanks
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.
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
!
Post by Maciej Bylica
Thanks for prompt answer.
No, i am not using CCP.
As i see OPTIONS ping does not match with any dialpeer
//3652/95FFAA748E45/SIP/Info/info/1024/ccsipInitPldCallingInfo: non-numeric
calling number: *stringhere*
//3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetViaHostInURLFormat: VIA
URL:sip:10.10.10.10:5060, Host:100.64.4.31
//3652/95FFAA748E45/SIP/Info/verbose/67584/sipSPIGetShrlPeer: Try match
incoming dialpeer for Calling number: : *stringhere*
input arg error
//3652/95FFAA748E45/SIP/Info/critical/10240/sipSPIGetCallConfig: No match
found for P-Called-Party-ID
input argument error
//3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition
tag absent in Require/Supported header
//3652/95FFAA748E45/SIP/Info/verbose/2048/sipSPIGetCallConfig: Media
Antitrombone disabled
//3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the
configured mode as FLOW-THROUGH
//3652/95FFAA748E45/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder
high-density disabled
//3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode
set to FLOW_THROUGH
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: Non dial peer
leg - using RTP Supported Codecs
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 18
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 0
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 8
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 9
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 4
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 2
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 15
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 255
MF: Not a Forked SIP leg..
//3652/95FFAA748E45/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp
configure for this leg.
peer_callID=0
MF: *Dial-peer is absent*..
//3652/95FFAA748E45/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state
= 0 & New state = -1
MF: Anchor leg config reset done...
MF:video profile Dial-peer is absent..
OPTIONS sip:domain.name.here:5060 SIP/2.0
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
Checking Invite Dialog
*****CCB found in UAS Request table. ccb=0x2766B958
//3653/9862338A8E46/SIP/Info/info/4096/sipSPICheckFromToRequest: Trying
with child CCB 0x0 index 0 curr_child 0
Failed FROM/TO Request check - IGNORE IF HAIRPIN CALL
....
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.
Post by Nick Barnett
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...
Post by Maciej Bylica
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.
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//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 8694911: *Could not add ccb to table*.
ccb=0x258D7210
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
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
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//146857/5A42A0608E30/SIP/State/sipSPIChangeState: 0x258B1110 : State
change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT,
SUBSTATE_NONE)
//146857/5A42A0608E30/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to
table. ccb=0x258B1110
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3 balance
1
Adding call id 23DA9 to table
ccsip_spi_get_msg_type returned: 3 for event 38
//-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created
msg=0x203FFDA4 with refCount = 1
Associated container=0x2673A528 to Options Response
sipSPIAppHandleContainerBody len 164
msg=0x203FFDA4, addr=11.11.11.11, port=5060, sentBy_port=5060, local_addr=,
is_req=0, transport=1, switch=0, callBack=0x4F48054
//146857/5A42A0608E30/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP
extension config:1, check sys cfg:1
//146857/5A42A0608E30/SIP/Transport/sipSPITransportSendMessage: Proceedable
for sending msg immediately
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Trying to
send resp=0x203FFDA4 to default port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering
gcb=0x258B1110 with connection=0x2426673C context list
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Connection
obtained...sending msg=0x203FFDA4
//-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 8625125: SIP/2.0 200 OK#015
Could someone help me with this? I really appreciate your advice.
Maciej
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
Maciej Bylica
2018-10-10 07:13:17 UTC
Permalink
Hello

Anthony, thanks for the hint, but you were right this is not the core of
the issue.

I made some test via sipp with following results
1)
Test: Send 15xOPTIONS with the same Call-ID and From-tag
Result: All OPTIONS were replied

2)
Test: shortly after completing the above test I made another test: Send
15xOPTIONS with the same Call-ID as previously but different From-tag.
Result: None of the OPTIONS we’re replied.

3)
Test: Test 2 was re-run after a while
Result: All OPTIONS were replied

So it seems Cisco records the Call-ID and From-tag somewhere in memory and
drops subsequent OPTIONS with the same Call-ID and different From-tag that
come from the same endpoint for some time.

I have similar situation here.
The customer we are trying to connect sends several OPTIONS within
miliseconds.
First OPTIONS is replied properly, but subsequent packets with the same
Call-ID and different From-tag dropped.

Is there any solution for this.
Our customer is very reluctant to proceed with any changes (another open
source SIP proxies replies all the OPTIONS).

Thanks
Maciej.
I hope you saw that I wrote "Pseudo Config" and don't just try to copy and
paste that. I'm also not very convinced that this is the core of your
issue, but you're more than welcome to give it a try.
You said the first OPTIONS does respond, so I'm guessing it's not going to
be a binding error. In fact, if it was a binding error, OPTIONS would
still respond, it would just have wrong IP info in the headers.
Anyway, good luck with that test.
Post by Maciej Bylica
Thanks, i am about to modify the config to check.
Many thanks
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.
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
!
Post by Maciej Bylica
Thanks for prompt answer.
No, i am not using CCP.
As i see OPTIONS ping does not match with any dialpeer
//3652/95FFAA748E45/SIP/Info/info/1024/ccsipInitPldCallingInfo: non-numeric
calling number: *stringhere*
//3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetViaHostInURLFormat: VIA
URL:sip:10.10.10.10:5060, Host:100.64.4.31
//3652/95FFAA748E45/SIP/Info/verbose/67584/sipSPIGetShrlPeer: Try match
incoming dialpeer for Calling number: : *stringhere*
input arg error
//3652/95FFAA748E45/SIP/Info/critical/10240/sipSPIGetCallConfig: No match
found for P-Called-Party-ID
input argument error
//3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition
tag absent in Require/Supported header
//3652/95FFAA748E45/SIP/Info/verbose/2048/sipSPIGetCallConfig: Media
Antitrombone disabled
//3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the
configured mode as FLOW-THROUGH
//3652/95FFAA748E45/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder
high-density disabled
//3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode
set to FLOW_THROUGH
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: Non dial peer
leg - using RTP Supported Codecs
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 18
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 0
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 8
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 9
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 4
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 2
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 15
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 255
MF: Not a Forked SIP leg..
//3652/95FFAA748E45/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp
configure for this leg.
peer_callID=0
MF: *Dial-peer is absent*..
//3652/95FFAA748E45/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state
= 0 & New state = -1
MF: Anchor leg config reset done...
MF:video profile Dial-peer is absent..
OPTIONS sip:domain.name.here:5060 SIP/2.0
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
Checking Invite Dialog
*****CCB found in UAS Request table. ccb=0x2766B958
//3653/9862338A8E46/SIP/Info/info/4096/sipSPICheckFromToRequest: Trying
with child CCB 0x0 index 0 curr_child 0
Failed FROM/TO Request check - IGNORE IF HAIRPIN CALL
....
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.
Post by Nick Barnett
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...
Post by Maciej Bylica
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.
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//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 8694911: *Could not add ccb to table*.
ccb=0x258D7210
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
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
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//146857/5A42A0608E30/SIP/State/sipSPIChangeState: 0x258B1110 : State
change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT,
SUBSTATE_NONE)
//146857/5A42A0608E30/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to
table. ccb=0x258B1110
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3 balance
1
Adding call id 23DA9 to table
ccsip_spi_get_msg_type returned: 3 for event 38
//-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created
msg=0x203FFDA4 with refCount = 1
Associated container=0x2673A528 to Options Response
sipSPIAppHandleContainerBody len 164
msg=0x203FFDA4, addr=11.11.11.11, port=5060, sentBy_port=5060, local_addr=,
is_req=0, transport=1, switch=0, callBack=0x4F48054
//146857/5A42A0608E30/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP
extension config:1, check sys cfg:1
//146857/5A42A0608E30/SIP/Transport/sipSPITransportSendMessage: Proceedable
for sending msg immediately
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Trying to
send resp=0x203FFDA4 to default port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering
gcb=0x258B1110 with connection=0x2426673C context list
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Connection
obtained...sending msg=0x203FFDA4
//-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 8625125: SIP/2.0 200 OK#015
Could someone help me with this? I really appreciate your advice.
Maciej
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
Maciej Bylica
2018-10-11 14:51:15 UTC
Permalink
Hello

Do you have an idea how to get around this problem?
Have you ever encountered such limitations in the process of processing
OPTIONS packages?

Thanks
Maciej.
Post by Maciej Bylica
Hello
Anthony, thanks for the hint, but you were right this is not the core of
the issue.
I made some test via sipp with following results
1)
Test: Send 15xOPTIONS with the same Call-ID and From-tag
Result: All OPTIONS were replied
2)
Test: shortly after completing the above test I made another test: Send
15xOPTIONS with the same Call-ID as previously but different From-tag.
Result: None of the OPTIONS we’re replied.
3)
Test: Test 2 was re-run after a while
Result: All OPTIONS were replied
So it seems Cisco records the Call-ID and From-tag somewhere in memory and
drops subsequent OPTIONS with the same Call-ID and different From-tag that
come from the same endpoint for some time.
I have similar situation here.
The customer we are trying to connect sends several OPTIONS within
miliseconds.
First OPTIONS is replied properly, but subsequent packets with the same
Call-ID and different From-tag dropped.
Is there any solution for this.
Our customer is very reluctant to proceed with any changes (another open
source SIP proxies replies all the OPTIONS).
Thanks
Maciej.
I hope you saw that I wrote "Pseudo Config" and don't just try to copy
and paste that. I'm also not very convinced that this is the core of your
issue, but you're more than welcome to give it a try.
You said the first OPTIONS does respond, so I'm guessing it's not going
to be a binding error. In fact, if it was a binding error, OPTIONS would
still respond, it would just have wrong IP info in the headers.
Anyway, good luck with that test.
Post by Maciej Bylica
Thanks, i am about to modify the config to check.
Many thanks
wt., 9 paź 2018 o 20:58 Anthony Holloway <
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.
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
!
Post by Maciej Bylica
Thanks for prompt answer.
No, i am not using CCP.
As i see OPTIONS ping does not match with any dialpeer
//3652/95FFAA748E45/SIP/Info/info/1024/ccsipInitPldCallingInfo: non-numeric
calling number: *stringhere*
//3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetViaHostInURLFormat: VIA
URL:sip:10.10.10.10:5060, Host:100.64.4.31
//3652/95FFAA748E45/SIP/Info/verbose/67584/sipSPIGetShrlPeer: Try match
incoming dialpeer for Calling number: : *stringhere*
input arg error
//3652/95FFAA748E45/SIP/Info/critical/10240/sipSPIGetCallConfig: No match
found for P-Called-Party-ID
input argument error
//3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition
tag absent in Require/Supported header
//3652/95FFAA748E45/SIP/Info/verbose/2048/sipSPIGetCallConfig: Media
Antitrombone disabled
//3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the
configured mode as FLOW-THROUGH
//3652/95FFAA748E45/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder
high-density disabled
//3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode
set to FLOW_THROUGH
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: Non dial peer
leg - using RTP Supported Codecs
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 18
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 0
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 8
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 9
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 4
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 2
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 15
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 255
MF: Not a Forked SIP leg..
//3652/95FFAA748E45/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp
configure for this leg.
peer_callID=0
MF: *Dial-peer is absent*..
//3652/95FFAA748E45/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state
= 0 & New state = -1
MF: Anchor leg config reset done...
MF:video profile Dial-peer is absent..
OPTIONS sip:domain.name.here:5060 SIP/2.0
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
Checking Invite Dialog
*****CCB found in UAS Request table. ccb=0x2766B958
//3653/9862338A8E46/SIP/Info/info/4096/sipSPICheckFromToRequest: Trying
with child CCB 0x0 index 0 curr_child 0
Failed FROM/TO Request check - IGNORE IF HAIRPIN CALL
....
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.
Post by Nick Barnett
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...
Post by Maciej Bylica
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.
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//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 8694911: *Could not add ccb to table*.
ccb=0x258D7210
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
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
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//146857/5A42A0608E30/SIP/State/sipSPIChangeState: 0x258B1110 : State
change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT,
SUBSTATE_NONE)
//146857/5A42A0608E30/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to
table. ccb=0x258B1110
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3 balance
1
Adding call id 23DA9 to table
ccsip_spi_get_msg_type returned: 3 for event 38
//-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created
msg=0x203FFDA4 with refCount = 1
Associated container=0x2673A528 to Options Response
sipSPIAppHandleContainerBody len 164
msg=0x203FFDA4, addr=11.11.11.11, port=5060, sentBy_port=5060, local_addr=,
is_req=0, transport=1, switch=0, callBack=0x4F48054
//146857/5A42A0608E30/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP
extension config:1, check sys cfg:1
//146857/5A42A0608E30/SIP/Transport/sipSPITransportSendMessage: Proceedable
for sending msg immediately
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Trying to
send resp=0x203FFDA4 to default port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering
gcb=0x258B1110 with connection=0x2426673C context list
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Connection
obtained...sending msg=0x203FFDA4
//-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 8625125: SIP/2.0 200 OK#015
Could someone help me with this? I really appreciate your advice.
Maciej
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
Nick Barnett
2018-10-11 18:36:58 UTC
Permalink
I don’t know what the problem is either. Maybe if you grab ccapi inout
debugs at the same time, your voice service voip section (at least, whole
config would be better), sh ver, and show run | sec voice. Maybe even do a
debug ccsip all if you have the ability to do that and NOT crash your CUBE.
Obviously don’t debug ccsip all without thinking about what that will do.



Even with all of that, I’m not sure I’ll have an answer, but I’ll look.
I’ve had similar issues with my CUBEs and it was due to binding issues and
another time it was a straight up bug and I had to bounce the box (which
“fixed” it). I don’t know why your initial debug was showing “could not
add ccb to table” and I’m not even sure which CCB it’s talking about. My
thoughts were that is customer callback
 but I’m probably wrong on that one.



Nick

On Thu, Oct 11, 2018 at 11:11 AM Anthony Holloway <
I feel obligated to reply, since I chimed in earlier....unfortunately, I
don't have any ideas for you. In fact, I have seen CUBE just ignore
incoming SIP messages before, both OPTIONS and INVITEs alike. Not many
occasions, just a few. I have never gotten resolution on it, it has either
fixed itself, or in one special case, still happens. It's my own, in
fact. It still randomly ignores inbound INVITES from my ITSP. Fixing it,
is on my to-do list, but... The cobbler's children are always the
worst-shod
<https://english.stackexchange.com/questions/46681/a-saying-indicating-how-some-professionals-dont-apply-their-skills-for-themselv>.
The Calls Per Second on my CUBE is like 1.7, however, there are no other
calls being setup, torn down, sup service, etc, and CUBE still just ignores
its responsibility.
Post by Maciej Bylica
Hello
Do you have an idea how to get around this problem?
Have you ever encountered such limitations in the process of processing
OPTIONS packages?
Thanks
Maciej.
Post by Maciej Bylica
Hello
Anthony, thanks for the hint, but you were right this is not the core of
the issue.
I made some test via sipp with following results
1)
Test: Send 15xOPTIONS with the same Call-ID and From-tag
Result: All OPTIONS were replied
2)
Test: shortly after completing the above test I made another test: Send
15xOPTIONS with the same Call-ID as previously but different From-tag.
Result: None of the OPTIONS we’re replied.
3)
Test: Test 2 was re-run after a while
Result: All OPTIONS were replied
So it seems Cisco records the Call-ID and From-tag somewhere in memory
and drops subsequent OPTIONS with the same Call-ID and different From-tag
that come from the same endpoint for some time.
I have similar situation here.
The customer we are trying to connect sends several OPTIONS within
miliseconds.
First OPTIONS is replied properly, but subsequent packets with the same
Call-ID and different From-tag dropped.
Is there any solution for this.
Our customer is very reluctant to proceed with any changes (another open
source SIP proxies replies all the OPTIONS).
Thanks
Maciej.
wt., 9 paź 2018 o 23:45 Anthony Holloway <
I hope you saw that I wrote "Pseudo Config" and don't just try to copy
and paste that. I'm also not very convinced that this is the core of your
issue, but you're more than welcome to give it a try.
You said the first OPTIONS does respond, so I'm guessing it's not going
to be a binding error. In fact, if it was a binding error, OPTIONS would
still respond, it would just have wrong IP info in the headers.
Anyway, good luck with that test.
Post by Maciej Bylica
Thanks, i am about to modify the config to check.
Many thanks
wt., 9 paź 2018 o 20:58 Anthony Holloway <
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.
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
!
Post by Maciej Bylica
Thanks for prompt answer.
No, i am not using CCP.
As i see OPTIONS ping does not match with any dialpeer
//3652/95FFAA748E45/SIP/Info/info/1024/ccsipInitPldCallingInfo: non-numeric
calling number: *stringhere*
//3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetViaHostInURLFormat: VIA
URL:sip:10.10.10.10:5060, Host:100.64.4.31
//3652/95FFAA748E45/SIP/Info/verbose/67584/sipSPIGetShrlPeer: Try match
incoming dialpeer for Calling number: : *stringhere*
input arg error
//3652/95FFAA748E45/SIP/Info/critical/10240/sipSPIGetCallConfig: No match
found for P-Called-Party-ID
input argument error
//3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition
tag absent in Require/Supported header
//3652/95FFAA748E45/SIP/Info/verbose/2048/sipSPIGetCallConfig: Media
Antitrombone disabled
//3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the
configured mode as FLOW-THROUGH
//3652/95FFAA748E45/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder
high-density disabled
//3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode
set to FLOW_THROUGH
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: Non dial peer
leg - using RTP Supported Codecs
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 18
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 0
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 8
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 9
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 4
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 2
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 15
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 255
MF: Not a Forked SIP leg..
//3652/95FFAA748E45/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp
configure for this leg.
peer_callID=0
MF: *Dial-peer is absent*..
//3652/95FFAA748E45/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state
= 0 & New state = -1
MF: Anchor leg config reset done...
MF:video profile Dial-peer is absent..
OPTIONS sip:domain.name.here:5060 SIP/2.0
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
Checking Invite Dialog
*****CCB found in UAS Request table. ccb=0x2766B958
//3653/9862338A8E46/SIP/Info/info/4096/sipSPICheckFromToRequest: Trying
with child CCB 0x0 index 0 curr_child 0
Failed FROM/TO Request check - IGNORE IF HAIRPIN CALL
....
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.
Post by Nick Barnett
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...
Post by Maciej Bylica
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.
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//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 8694911: *Could not add ccb to table*.
ccb=0x258D7210
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
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
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//146857/5A42A0608E30/SIP/State/sipSPIChangeState: 0x258B1110 : State
change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT,
SUBSTATE_NONE)
//146857/5A42A0608E30/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to
table. ccb=0x258B1110
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3 balance
1
Adding call id 23DA9 to table
ccsip_spi_get_msg_type returned: 3 for event 38
//-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created
msg=0x203FFDA4 with refCount = 1
Associated container=0x2673A528 to Options Response
sipSPIAppHandleContainerBody len 164
msg=0x203FFDA4, addr=11.11.11.11, port=5060, sentBy_port=5060, local_addr=,
is_req=0, transport=1, switch=0, callBack=0x4F48054
//146857/5A42A0608E30/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP
extension config:1, check sys cfg:1
//146857/5A42A0608E30/SIP/Transport/sipSPITransportSendMessage: Proceedable
for sending msg immediately
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Trying to
send resp=0x203FFDA4 to default port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering
gcb=0x258B1110 with connection=0x2426673C context list
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Connection
obtained...sending msg=0x203FFDA4
//-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 8625125: SIP/2.0 200 OK#015
Could someone help me with this? I really appreciate your advice.
Maciej
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
Kent Roberts
2018-10-11 20:32:20 UTC
Permalink
Here is what I use:

voice-class sip options-keepalive up-interval 180 down-interval 60 retry 2

Sh dial-peer voice sum the Keepalive line will show busyout or active.
I don’t know what the problem is either. Maybe if you grab ccapi inout debugs at the same time, your voice service voip section (at least, whole config would be better), sh ver, and show run | sec voice. Maybe even do a debug ccsip all if you have the ability to do that and NOT crash your CUBE. Obviously don’t debug ccsip all without thinking about what that will do.
Even with all of that, I’m not sure I’ll have an answer, but I’ll look. I’ve had similar issues with my CUBEs and it was due to binding issues and another time it was a straight up bug and I had to bounce the box (which “fixed” it). I don’t know why your initial debug was showing “could not add ccb to table” and I’m not even sure which CCB it’s talking about. My thoughts were that is customer callback
 but I’m probably wrong on that one.
Nick
I feel obligated to reply, since I chimed in earlier....unfortunately, I don't have any ideas for you. In fact, I have seen CUBE just ignore incoming SIP messages before, both OPTIONS and INVITEs alike. Not many occasions, just a few. I have never gotten resolution on it, it has either fixed itself, or in one special case, still happens. It's my own, in fact. It still randomly ignores inbound INVITES from my ITSP. Fixing it, is on my to-do list, but... The cobbler's children are always the worst-shod <https://english.stackexchange.com/questions/46681/a-saying-indicating-how-some-professionals-dont-apply-their-skills-for-themselv>. The Calls Per Second on my CUBE is like 1.7, however, there are no other calls being setup, torn down, sup service, etc, and CUBE still just ignores its responsibility.
Hello
Do you have an idea how to get around this problem?
Have you ever encountered such limitations in the process of processing OPTIONS packages?
Thanks
Maciej.
Hello
Anthony, thanks for the hint, but you were right this is not the core of the issue.
I made some test via sipp with following results
1)
Test: Send 15xOPTIONS with the same Call-ID and From-tag
Result: All OPTIONS were replied
2)
Test: shortly after completing the above test I made another test: Send 15xOPTIONS with the same Call-ID as previously but different From-tag.
Result: None of the OPTIONS we’re replied.
3)
Test: Test 2 was re-run after a while
Result: All OPTIONS were replied
So it seems Cisco records the Call-ID and From-tag somewhere in memory and drops subsequent OPTIONS with the same Call-ID and different From-tag that come from the same endpoint for some time.
I have similar situation here.
The customer we are trying to connect sends several OPTIONS within miliseconds.
First OPTIONS is replied properly, but subsequent packets with the same Call-ID and different From-tag dropped.
Is there any solution for this.
Our customer is very reluctant to proceed with any changes (another open source SIP proxies replies all the OPTIONS).
Thanks
Maciej.
I hope you saw that I wrote "Pseudo Config" and don't just try to copy and paste that. I'm also not very convinced that this is the core of your issue, but you're more than welcome to give it a try.
You said the first OPTIONS does respond, so I'm guessing it's not going to be a binding error. In fact, if it was a binding error, OPTIONS would still respond, it would just have wrong IP info in the headers.
Anyway, good luck with that test.
Thanks, i am about to modify the config to check.
Many thanks
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.
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
!
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 <http://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
input arg error
Oct 9 17:50:04.068: //3652/95FFAA748E45/SIP/Info/critical/10240/sipSPIGetCallConfig: No match found for P-Called-Party-ID
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
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...
MF:video profile Dial-peer is absent..
OPTIONS sip:domain.name.here:5060 SIP/2.0
I do not have any script in use there, the configuration in pretty basic.
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
Failed FROM/TO Request check - IGNORE IF HAIRPIN CALL
....
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.
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...
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.
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 8694911: Could not add ccb to table. ccb=0x258D7210 key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
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
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 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 8625125: SIP/2.0 200 OK#015
Could someone help me with this? I really appreciate your advice.
Maciej
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip <https://puck.nether.net/mailman/listinfo/cisco-voip>
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip <https://puck.nether.net/mailman/listinfo/cisco-voip>
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
Kent Roberts
2018-10-11 20:57:21 UTC
Permalink
Oh sorry, I didn’t catch that on the receiving part. Well, I probably should re-look at some of the commands, but we were one of the first adopters of SIP and not all the defaults that exist today, existed back then. Some of it got left in cause it works with the carrier. :) Some of it was also trial and error with the carrier, and well when it starts working sometimes things don’t get revisited
. Hows that for an answer!!!
Kent,
I'm not sure why you sent that. The problem is not with sending OPTION Ping, it's with responding to received OPTION Ping.
"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"
voice class sip options-keepalive up-interval 60 down-interval 30 retry 5
What is your reason for changing it from the default? The rule of thumb is "use the defaults, unless you have a reason not to"
I see the obvious answer here: it pings less often; however, it's the why which I am interested in.
Thanks for sharing what you do.
voice-class sip options-keepalive up-interval 180 down-interval 60 retry 2
Sh dial-peer voice sum the Keepalive line will show busyout or active.
I don’t know what the problem is either. Maybe if you grab ccapi inout debugs at the same time, your voice service voip section (at least, whole config would be better), sh ver, and show run | sec voice. Maybe even do a debug ccsip all if you have the ability to do that and NOT crash your CUBE. Obviously don’t debug ccsip all without thinking about what that will do.
Even with all of that, I’m not sure I’ll have an answer, but I’ll look. I’ve had similar issues with my CUBEs and it was due to binding issues and another time it was a straight up bug and I had to bounce the box (which “fixed” it). I don’t know why your initial debug was showing “could not add ccb to table” and I’m not even sure which CCB it’s talking about. My thoughts were that is customer callback
 but I’m probably wrong on that one.
Nick
I feel obligated to reply, since I chimed in earlier....unfortunately, I don't have any ideas for you. In fact, I have seen CUBE just ignore incoming SIP messages before, both OPTIONS and INVITEs alike. Not many occasions, just a few. I have never gotten resolution on it, it has either fixed itself, or in one special case, still happens. It's my own, in fact. It still randomly ignores inbound INVITES from my ITSP. Fixing it, is on my to-do list, but... The cobbler's children are always the worst-shod <https://english.stackexchange.com/questions/46681/a-saying-indicating-how-some-professionals-dont-apply-their-skills-for-themselv>. The Calls Per Second on my CUBE is like 1.7, however, there are no other calls being setup, torn down, sup service, etc, and CUBE still just ignores its responsibility.
Hello
Do you have an idea how to get around this problem?
Have you ever encountered such limitations in the process of processing OPTIONS packages?
Thanks
Maciej.
Hello
Anthony, thanks for the hint, but you were right this is not the core of the issue.
I made some test via sipp with following results
1)
Test: Send 15xOPTIONS with the same Call-ID and From-tag
Result: All OPTIONS were replied
2)
Test: shortly after completing the above test I made another test: Send 15xOPTIONS with the same Call-ID as previously but different From-tag.
Result: None of the OPTIONS we’re replied.
3)
Test: Test 2 was re-run after a while
Result: All OPTIONS were replied
So it seems Cisco records the Call-ID and From-tag somewhere in memory and drops subsequent OPTIONS with the same Call-ID and different From-tag that come from the same endpoint for some time.
I have similar situation here.
The customer we are trying to connect sends several OPTIONS within miliseconds.
First OPTIONS is replied properly, but subsequent packets with the same Call-ID and different From-tag dropped.
Is there any solution for this.
Our customer is very reluctant to proceed with any changes (another open source SIP proxies replies all the OPTIONS).
Thanks
Maciej.
I hope you saw that I wrote "Pseudo Config" and don't just try to copy and paste that. I'm also not very convinced that this is the core of your issue, but you're more than welcome to give it a try.
You said the first OPTIONS does respond, so I'm guessing it's not going to be a binding error. In fact, if it was a binding error, OPTIONS would still respond, it would just have wrong IP info in the headers.
Anyway, good luck with that test.
Thanks, i am about to modify the config to check.
Many thanks
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.
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
!
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 <http://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
input arg error
Oct 9 17:50:04.068: //3652/95FFAA748E45/SIP/Info/critical/10240/sipSPIGetCallConfig: No match found for P-Called-Party-ID
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
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...
MF:video profile Dial-peer is absent..
OPTIONS sip:domain.name.here:5060 <> SIP/2.0
I do not have any script in use there, the configuration in pretty basic.
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
Failed FROM/TO Request check - IGNORE IF HAIRPIN CALL
....
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.
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...
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.
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 8694911: Could not add ccb to table. ccb=0x258D7210 key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
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
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 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 8625125: SIP/2.0 200 OK#015
Could someone help me with this? I really appreciate your advice.
Maciej
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip <https://puck.nether.net/mailman/listinfo/cisco-voip>
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip <https://puck.nether.net/mailman/listinfo/cisco-voip>
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip <https://puck.nether.net/mailman/listinfo/cisco-voip>
Kent Roberts
2018-10-11 20:59:30 UTC
Permalink
Should also throw out that, one of the carriers, didn’t care about options as long as there was something hitting it.
Post by Kent Roberts
Oh sorry, I didn’t catch that on the receiving part. Well, I probably should re-look at some of the commands, but we were one of the first adopters of SIP and not all the defaults that exist today, existed back then. Some of it got left in cause it works with the carrier. :) Some of it was also trial and error with the carrier, and well when it starts working sometimes things don’t get revisited
. Hows that for an answer!!!
Kent,
I'm not sure why you sent that. The problem is not with sending OPTION Ping, it's with responding to received OPTION Ping.
"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"
voice class sip options-keepalive up-interval 60 down-interval 30 retry 5
What is your reason for changing it from the default? The rule of thumb is "use the defaults, unless you have a reason not to"
I see the obvious answer here: it pings less often; however, it's the why which I am interested in.
Thanks for sharing what you do.
voice-class sip options-keepalive up-interval 180 down-interval 60 retry 2
Sh dial-peer voice sum the Keepalive line will show busyout or active.
I don’t know what the problem is either. Maybe if you grab ccapi inout debugs at the same time, your voice service voip section (at least, whole config would be better), sh ver, and show run | sec voice. Maybe even do a debug ccsip all if you have the ability to do that and NOT crash your CUBE. Obviously don’t debug ccsip all without thinking about what that will do.
Even with all of that, I’m not sure I’ll have an answer, but I’ll look. I’ve had similar issues with my CUBEs and it was due to binding issues and another time it was a straight up bug and I had to bounce the box (which “fixed” it). I don’t know why your initial debug was showing “could not add ccb to table” and I’m not even sure which CCB it’s talking about. My thoughts were that is customer callback
 but I’m probably wrong on that one.
Nick
I feel obligated to reply, since I chimed in earlier....unfortunately, I don't have any ideas for you. In fact, I have seen CUBE just ignore incoming SIP messages before, both OPTIONS and INVITEs alike. Not many occasions, just a few. I have never gotten resolution on it, it has either fixed itself, or in one special case, still happens. It's my own, in fact. It still randomly ignores inbound INVITES from my ITSP. Fixing it, is on my to-do list, but... The cobbler's children are always the worst-shod <https://english.stackexchange.com/questions/46681/a-saying-indicating-how-some-professionals-dont-apply-their-skills-for-themselv>. The Calls Per Second on my CUBE is like 1.7, however, there are no other calls being setup, torn down, sup service, etc, and CUBE still just ignores its responsibility.
Hello
Do you have an idea how to get around this problem?
Have you ever encountered such limitations in the process of processing OPTIONS packages?
Thanks
Maciej.
Hello
Anthony, thanks for the hint, but you were right this is not the core of the issue.
I made some test via sipp with following results
1)
Test: Send 15xOPTIONS with the same Call-ID and From-tag
Result: All OPTIONS were replied
2)
Test: shortly after completing the above test I made another test: Send 15xOPTIONS with the same Call-ID as previously but different From-tag.
Result: None of the OPTIONS we’re replied.
3)
Test: Test 2 was re-run after a while
Result: All OPTIONS were replied
So it seems Cisco records the Call-ID and From-tag somewhere in memory and drops subsequent OPTIONS with the same Call-ID and different From-tag that come from the same endpoint for some time.
I have similar situation here.
The customer we are trying to connect sends several OPTIONS within miliseconds.
First OPTIONS is replied properly, but subsequent packets with the same Call-ID and different From-tag dropped.
Is there any solution for this.
Our customer is very reluctant to proceed with any changes (another open source SIP proxies replies all the OPTIONS).
Thanks
Maciej.
I hope you saw that I wrote "Pseudo Config" and don't just try to copy and paste that. I'm also not very convinced that this is the core of your issue, but you're more than welcome to give it a try.
You said the first OPTIONS does respond, so I'm guessing it's not going to be a binding error. In fact, if it was a binding error, OPTIONS would still respond, it would just have wrong IP info in the headers.
Anyway, good luck with that test.
Thanks, i am about to modify the config to check.
Many thanks
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.
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
!
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 <http://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
input arg error
Oct 9 17:50:04.068: //3652/95FFAA748E45/SIP/Info/critical/10240/sipSPIGetCallConfig: No match found for P-Called-Party-ID
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
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...
MF:video profile Dial-peer is absent..
OPTIONS sip:domain.name.here:5060 <> SIP/2.0
I do not have any script in use there, the configuration in pretty basic.
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
Failed FROM/TO Request check - IGNORE IF HAIRPIN CALL
....
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.
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...
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.
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 8694911: Could not add ccb to table. ccb=0x258D7210 key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
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
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 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 8625125: SIP/2.0 200 OK#015
Could someone help me with this? I really appreciate your advice.
Maciej
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip <https://puck.nether.net/mailman/listinfo/cisco-voip>
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip <https://puck.nether.net/mailman/listinfo/cisco-voip>
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip <https://puck.nether.net/mailman/listinfo/cisco-voip>
Maciej Bylica
2018-10-16 10:02:08 UTC
Permalink
We will try to convince the customer to adjust the settings on his side
(unique Call-ID for every OPTIONs would do the job).
As a workaround we do have C3845 with 12.x IOS :)

Many thanks for your help
Maciej.
Fair enough. We're not always paid to perform the second O in PPDIOO.
Your answer is better than "I don't know" ;) Again, thanks for sharing
your experiences.
Post by Kent Roberts
Oh sorry, I didn’t catch that on the receiving part. Well, I probably
should re-look at some of the commands, but we were one of the first
adopters of SIP and not all the defaults that exist today, existed back
then. Some of it got left in cause it works with the carrier. :)
Some of it was also trial and error with the carrier, and well when it
starts working sometimes things don’t get revisited
. Hows that for an
answer!!!
On Oct 11, 2018, at 2:42 PM, Anthony Holloway <
Kent,
I'm not sure why you sent that. The problem is not with sending OPTION
Ping, it's with responding to received OPTION Ping.
*"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"*
voice class sip options-keepalive up-interval 60 down-interval 30 retry 5
What is your reason for changing it from the default? The rule of thumb
is "use the defaults, unless you have a reason not to"
I see the obvious answer here: it pings less often; however, it's the
*why* which I am interested in.
Thanks for sharing what you do.
Post by Kent Roberts
voice-class sip options-keepalive up-interval 180 down-interval 60 retry 2
Sh dial-peer voice sum the Keepalive line will show busyout or active.
I don’t know what the problem is either. Maybe if you grab ccapi inout
debugs at the same time, your voice service voip section (at least, whole
config would be better), sh ver, and show run | sec voice. Maybe even do a
debug ccsip all if you have the ability to do that and NOT crash your CUBE.
Obviously don’t debug ccsip all without thinking about what that will do.
Even with all of that, I’m not sure I’ll have an answer, but I’ll look.
I’ve had similar issues with my CUBEs and it was due to binding issues and
another time it was a straight up bug and I had to bounce the box (which
“fixed” it). I don’t know why your initial debug was showing “could
not add ccb to table” and I’m not even sure which CCB it’s talking about.
My thoughts were that is customer callback
 but I’m probably wrong on that
one.
Nick
On Thu, Oct 11, 2018 at 11:11 AM Anthony Holloway <
I feel obligated to reply, since I chimed in earlier....unfortunately,
I don't have any ideas for you. In fact, I have seen CUBE just ignore
incoming SIP messages before, both OPTIONS and INVITEs alike. Not many
occasions, just a few. I have never gotten resolution on it, it has either
fixed itself, or in one special case, still happens. It's my own, in
fact. It still randomly ignores inbound INVITES from my ITSP. Fixing it,
is on my to-do list, but... The cobbler's children are always the
worst-shod
<https://english.stackexchange.com/questions/46681/a-saying-indicating-how-some-professionals-dont-apply-their-skills-for-themselv>.
The Calls Per Second on my CUBE is like 1.7, however, there are no other
calls being setup, torn down, sup service, etc, and CUBE still just ignores
its responsibility.
Post by Maciej Bylica
Hello
Do you have an idea how to get around this problem?
Have you ever encountered such limitations in the process of
processing OPTIONS packages?
Thanks
Maciej.
Post by Maciej Bylica
Hello
Anthony, thanks for the hint, but you were right this is not the core
of the issue.
I made some test via sipp with following results
1)
Test: Send 15xOPTIONS with the same Call-ID and From-tag
Result: All OPTIONS were replied
2)
Send 15xOPTIONS with the same Call-ID as previously but different From-tag.
Result: None of the OPTIONS we’re replied.
3)
Test: Test 2 was re-run after a while
Result: All OPTIONS were replied
So it seems Cisco records the Call-ID and From-tag somewhere in
memory and drops subsequent OPTIONS with the same Call-ID and different
From-tag that come from the same endpoint for some time.
I have similar situation here.
The customer we are trying to connect sends several OPTIONS within miliseconds.
First OPTIONS is replied properly, but subsequent packets with the
same Call-ID and different From-tag dropped.
Is there any solution for this.
Our customer is very reluctant to proceed with any changes (another
open source SIP proxies replies all the OPTIONS).
Thanks
Maciej.
wt., 9 paź 2018 o 23:45 Anthony Holloway <
I hope you saw that I wrote "Pseudo Config" and don't just try to
copy and paste that. I'm also not very convinced that this is the core of
your issue, but you're more than welcome to give it a try.
You said the first OPTIONS does respond, so I'm guessing it's not
going to be a binding error. In fact, if it was a binding error, OPTIONS
would still respond, it would just have wrong IP info in the headers.
Anyway, good luck with that test.
Post by Maciej Bylica
Thanks, i am about to modify the config to check.
Many thanks
wt., 9 paź 2018 o 20:58 Anthony Holloway <
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.
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
!
Post by Maciej Bylica
Thanks for prompt answer.
No, i am not using CCP.
As i see OPTIONS ping does not match with any dialpeer
//3652/95FFAA748E45/SIP/Info/info/1024/ccsipInitPldCallingInfo: non-numeric
calling number: *stringhere*
//3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetViaHostInURLFormat: VIA
URL:sip:10.10.10.10:5060, Host:100.64.4.31
//3652/95FFAA748E45/SIP/Info/verbose/67584/sipSPIGetShrlPeer: Try match
incoming dialpeer for Calling number: : *stringhere*
input arg error
//3652/95FFAA748E45/SIP/Info/critical/10240/sipSPIGetCallConfig: No match
found for P-Called-Party-ID
input argument error
//3652/95FFAA748E45/SIP/Info/verbose/1024/sipSPIGetCallConfig: Precondition
tag absent in Require/Supported header
//3652/95FFAA748E45/SIP/Info/verbose/2048/sipSPIGetCallConfig: Media
Antitrombone disabled
//3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Storing the
configured mode as FLOW-THROUGH
//3652/95FFAA748E45/SIP/Info/info/2304/sipSPISetMediaFlowMode: xcoder
high-density disabled
//3652/95FFAA748E45/SIP/Info/info/8192/sipSPISetMediaFlowMode: Flow Mode
set to FLOW_THROUGH
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: Non dial peer
leg - using RTP Supported Codecs
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 18
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 0
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 8
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 9
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 4
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 2
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 15
//3652/95FFAA748E45/SIP/Info/info/10240/sipSPIGetCallConfig: RTP Preferred
Codecs supported by GW 255
MF: Not a Forked SIP leg..
//3652/95FFAA748E45/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp
configure for this leg.
peer_callID=0
MF: *Dial-peer is absent*..
//3652/95FFAA748E45/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state
= 0 & New state = -1
MF: Anchor leg config reset done...
MF:video profile Dial-peer is absent..
OPTIONS sip:domain.name.here:5060 SIP/2.0
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
Checking Invite Dialog
*****CCB found in UAS Request table. ccb=0x2766B958
//3653/9862338A8E46/SIP/Info/info/4096/sipSPICheckFromToRequest: Trying
with child CCB 0x0 index 0 curr_child 0
Failed FROM/TO Request check - IGNORE IF HAIRPIN CALL
....
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.
Post by Nick Barnett
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 <
Post by Maciej Bylica
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.
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//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 8694911: *Could not add ccb to
table*. ccb=0x258D7210
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3
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
SIPSPI_EV_CC_OPTIONS_RESP
ccsip_api_options_ind returned: SIP_SUCCESS
//146857/5A42A0608E30/SIP/State/sipSPIChangeState: 0x258B1110 : State
change from (STATE_IDLE, SUBSTATE_NONE) to (SIP_STATE_OPTIONS_WAIT,
SUBSTATE_NONE)
//146857/5A42A0608E30/SIP/Info/verbose/4096/sipSPIUaddCcbToTable: Added to
table. ccb=0x258B1110
key=c3c4f5582a4bfa1ff4b7e741c3cb6c6822f738b4cd7e78633fc70f5441197d3 balance
1
Adding call id 23DA9 to table
ccsip_spi_get_msg_type returned: 3 for event 38
//-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_create: created
msg=0x203FFDA4 with refCount = 1
Associated container=0x2673A528 to Options Response
sipSPIAppHandleContainerBody len 164
msg=0x203FFDA4, addr=11.11.11.11, port=5060, sentBy_port=5060, local_addr=,
is_req=0, transport=1, switch=0, callBack=0x4F48054
//146857/5A42A0608E30/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP
extension config:1, check sys cfg:1
//146857/5A42A0608E30/SIP/Transport/sipSPITransportSendMessage: Proceedable
for sending msg immediately
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Trying to
send resp=0x203FFDA4 to default port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering
gcb=0x258B1110 with connection=0x2426673C context list
//146857/5A42A0608E30/SIP/Transport/sipTransportLogicSendMsg: Connection
obtained...sending msg=0x203FFDA4
//-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 8625125: SIP/2.0 200 OK#015
Could someone help me with this? I really appreciate your advice.
Maciej
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
_______________________________________________
cisco-voip mailing list
https://puck.nether.net/mailman/listinfo/cisco-voip
Loading...