[cisco-voip] SIP 400 Bad request

Wed Mar 10 23:26:03 EST 2010

Thanks a lot for the suggestion. I'll ask the provider to put bracket
and see if calls goes thru.

regards,
jeff

On Wed, Mar 10, 2010 at 1:07 PM, Nick Matthews <matthnick at gmail.com> wrote:
> RFC 3261 would seem to agree for the From, Contact, and To headers:
>
>   The Contact, From, and To header fields contain a URI.  If the URI
>   contains a comma, question mark or semicolon, the URI MUST be
>   enclosed in angle brackets (< and >).  Any URI parameters are
>   contained within these brackets.  If the URI is not enclosed in angle
>   brackets, any semicolon-delimited parameters are header-parameters,
>   not URI parameters.
>
> But, RFC 3325 (P-asserted-identity) states that the formal syntax
> follows RFC 2234 (I know, FUN):
>
> The names <rulename>, <Rulename>, <RULENAME> and <rUlENamE> all refer
>   to the same rule.   Unlike original BNF, angle brackets ("<", ">")
> are not  required.
>   However, angle brackets may be used around a rule name whenever their
>   presence will facilitate discerning the use of  a rule name.  This is
>   typically restricted to rule name references in free-form prose, or
>   to distinguish partial rules that combine into a string not separated
>   by white space, such as shown in the discussion about repetition,
>   below.
>
>
> In short - see if your provider can put angle brackets on the paID.
> It's kind of a grey area for this particular header because you're
> bringing in a separate paID RFC for the enforcement.
>
> -nick
>
>
>
> On Tue, Mar 9, 2010 at 11:11 PM, Kevin Thorngren <kthorngr at cisco.com> wrote:
>> It looks like CUCM does not like the P-Asserted-identity header:
>> 03/03/2010 10:17:26.206
>> CCM|//SIP/SIPHandler/ccbId=0/scbId=0/checkSyntaxAndSelectAssertedHeader: PAI
>> result [16], total[0], sipUri[0], sipsUri[0],
>> telUri[0]|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::20000>
>> 03/03/2010 10:17:26.206
>> CCM|//SIP/SIPHandler/ccbId=0/scbId=0/extractAssertedInfo:
>> parseResult[16]|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::20000>
>> 03/03/2010 10:17:26.206
>> CCM|//SIP/Stack/Info/0xeb1e468/ccsip_api_call_setup_ind returned:
>> SIP_MSG_PARSE_ERR|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> The header in the Invite looks like this:
>> P-Asserted-Identity: sip:28303941 at 10.249.0.6;user=phone
>> Don't know for sure but I think it should look like this with <> surrounding
>> URI
>> P-Asserted-Identity: <sip:28303941 at 10.249.0.6;user=phone>
>> Kevin
>> On Mar 9, 2010, at 9:42 PM, Jefflin Choi wrote:
>>
>> Hi all,
>>
>> Thanks a lot for all the suggestions.
>> I am asking the provider now to double check their configs.
>>
>> Attached are the detailed sdi and sdl traces.
>> unfortunately, my reading experience with CCM trace is not so good.
>> 10.249.224.18 is the SBC's ip add. 8806301 is the cisco ip phone's number
>> being called. CCM's IP is 10.10.6.9.
>>
>> ------------------
>> Date: Wed, 03 Mar 2010 02:17:24 GMT
>> Allow: INVITE, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE,
>> NOTIFY
>> From: "hbuser"<sip:hbuser at 10.249.0.6:5061>;tag=ucAC100849
>> Content-Length: 0
>> To: <sip:10.249.190.2:5060>;tag=1033457050
>> Call-ID: 1A840A0000 at 10.249.0.6
>> Via: SIP/2.0/UDP 10.249.224.18:5060;branch=z9hG4bKlihiah10bo80pa08s2k1.1
>> CSeq: 1 OPTIONS
>>
>> |<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.23><IP::10.249.224.18><DEV::><LVL::State
>> Transition><MASK::20000>
>> 03/03/2010 10:17:24.447 CCM|EnvProcessUdpPort -
>> EnvProcessUdpHandler::fireSignal() varId =
>> 0|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.23><IP::10.249.224.18><DEV::><LVL::Arbitrary><MASK::0800>
>> 03/03/2010 10:17:24.447 CCM|EnvProcessUdpPort -
>> EnvProcessUdpHandler::send(buff, 380,
>> 10.249.224.18:5060)|<CLID::StandAloneCluster><NID::10.10.6.9><LVL::Arbitrary><MASK::0800>
>> 03/03/2010 10:17:26.205 CCM|EnvProcessUdpHandler::handle_input   Status: 0,
>> Id: 0|<CLID::StandAloneCluster><NID::10.10.6.9><LVL::Arbitrary><MASK::0800>
>> 03/03/2010 10:17:26.205 CCM|//SIP/SIPUdp/wait_UdpDataInd: Incoming SIP UDP
>> message size 1035 from 10.249.224.18:[5060]:
>> INVITE sip:8806301 at 10.10.6.9:5060;user=phone SIP/2.0
>> Via: SIP/2.0/UDP 10.249.224.18:5060;branch=z9hG4bKl2olcr10e0khva0832o1.1
>> From: "28303941"<sip:28303941 at 10.249.0.14:5061;user=phone>;tag=uc192E625E
>> To: <sip:028806301 at 10.249.0.6:5061;user=phone>
>> P-Asserted-Identity: sip:28303941 at 10.249.0.6;user=phone
>> Supported: 100rel,timer
>> Content-Type: application/sdp
>> Session-Expires: 1800
>> Call-ID: 1B840C0000 at 10.249.0.6
>> CSeq: 1 INVITE
>> Allow:
>> INVITE,ACK,OPTIONS,BYE,CANCEL,UPDATE,REGISTER,INFO,PRACK,SUBSCRIBE,NOTIFY,MESSAGE
>> Contact: <sip:28303941 at 10.249.224.18:5060;transport=udp>
>> Max-Forwards: 69
>> Content-Length: 411
>>
>> v=0
>> o=UTSTARCOM 0 0 IN IP4 10.249.224.18
>> s=-
>> c=IN IP4 10.249.224.18
>> t=0 0
>> m=audio 65190 RTP/AVP 8 127 18 0 4 102 15
>> a=sendrecv
>> a=fmtp:8 X-ptime: 20
>> a=fmtp:127 X-ptime: 20
>> a=fmtp:18 X-ptime: 20 30 40 10
>> a=fmtp:0 X-ptime: 20 15 10 5
>> a=fmtp:4 X-ptime: 30 60 90 120
>> a=fmtp:102 X-ptime: 15 10 5 0
>> a=fmtp:15 X-ptime: 20 15 10 5
>> a=rtpmap:127 telephone-event/8000
>> a=fmtp:127 0-15
>> a=rtpmap:102 vbd/8000
>> |<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::State
>> Transition><MASK::20000>
>> 03/03/2010 10:17:26.205 CCM|//SIP/Stack/Info/0x0/ccsip_spi_get_msg_type
>> returned: 2 for event
>> 1|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.205
>> CCM|//SIP/Stack/Transport/0x0/context=(nil)|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.205 CCM|//SIP/Stack/Info/0x0/Checking Invite
>> Dialog|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Info/0x0/Added context(0xeb1e468)
>> with key=[22] to
>> table|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Transport/0x0/Dialog Transaction
>> Address 10.249.224.18,Port 5060, Transport 1, SentBy Port
>> 5060|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/States/0xeb1e468/0xeb1e468 : State
>> change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE,
>> SUBSTATE_NONE)|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::State
>> Transition><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Transport/0x0/Dialog Transaction
>> Address 10.249.224.18,Port 5060, Transport 1, SentBy Port
>> 5060|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Transport/0x0/Dialog Transaction
>> Address 10.249.224.18,Port 5060, Transport 1, SentBy Port
>> 5060|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Info/0x0/No GTD found in inbound
>> container|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Info/0xeb1e468/****Adding to UAS
>> Request
>> table.|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Info/0xeb1e468/Added to table.
>> ccb=0xeb1e468
>> key=1B840C0000 at 10.249.0.68806301|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Info/0xeb1e468/Calling name
>> 28303941, number 28303941, Calling oct3 0x00, oct_3a 0x80, ext_priv 0x00,
>> Called number 8806301,
>> o|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Info/0xeb1e468/Carrier id code ,
>> prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp
>> NONE|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206
>> CCM|//SIP/SIPHandler/ccbId=0/scbId=0/sipSPIGetCallExtensionSupported:
>> SIPRel1xxEnabledServiceParamSetting=1 ,
>> ccb->pld.outboundRel1xx=1|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::20000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Info/0xeb1e468/Requires
>> reliable-provisional
>> support|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/SIPHandler/ccbId=0/scbId=0/sip_stop_timer:
>> type=SIP_TIMER_EXPIRES value=1800000
>> retries=0|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::20000>
>> 03/03/2010 10:17:26.206
>> CCM|//SIP/SIPHandler/ccbId=0/scbId=0/sip_start_timer: type=SIP_TIMER_EXPIRES
>> value=1800000
>> retries=0|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::20000>
>> 03/03/2010 10:17:26.206
>> CCM|//SIP/SIPHandler/ccbId=0/scbId=0/checkSyntaxAndSelectAssertedHeader: PAI
>> result [16], total[0], sipUri[0], sipsUri[0],
>> telUri[0]|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::20000>
>> 03/03/2010 10:17:26.206
>> CCM|//SIP/SIPHandler/ccbId=0/scbId=0/extractAssertedInfo:
>> parseResult[16]|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::20000>
>> 03/03/2010 10:17:26.206
>> CCM|//SIP/Stack/Info/0xeb1e468/ccsip_api_call_setup_ind returned:
>> SIP_MSG_PARSE_ERR|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Info/0xeb1e468/****Adding to UAS
>> Response
>> table.|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.206 CCM|//SIP/Stack/Info/0xeb1e468/Added to table.
>> ccb=0xeb1e468
>> key=1B840C0000 at 10.249.0.61534499114|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.207 CCM|//SIP/Stack/Transport/0xeb1e468/msg=0xdd435a8,
>> addr=10.249.224.18, port=5060, sentBy_port=5060, is_req=0, transport=1,
>> switch=0,
>> callBack=0x9cbab98|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.207 CCM|//SIP/Stack/Transport/0xeb1e468/Proceedable for
>> sending msg
>> immediately|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.207 CCM|//SIP/Stack/Transport/0xeb1e468/switch transport
>> is
>> 0|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.207 CCM|//SIP/Stack/Transport/0x0/Posting send for
>> msg=0xdd435a8, addr=10.249.224.18, port=5060, connId=0 for
>> UDP|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.207 CCM|//SIP/Stack/Info/0xeb1e468/Sent an 3456XX Error
>> Response|<CLID::StandAloneCluster><NID::10.10.6.9><CT::1,100,186,1.24><IP::10.249.224.18><DEV::><LVL::Detailed><MASK::40000>
>> 03/03/2010 10:17:26.207 CCM|//SIP/SIPUdp/wait_SdlSPISignal: Outgoing SIP UDP
>> message to 10.249.224.18:[5060]:
>> SIP/2.0 400 Bad Request
>> Date: Wed, 03 Mar 2010 02:17:26 GMT
>> From: "28303941"<sip:28303941 at 10.249.0.14:5061;user=phone>;tag=uc192E625E
>> Allow-Events: presence
>> Content-Length: 0
>> To: <sip:028806301 at 10.249.0.6:5061;user=phone>;tag=1534499114
>> Call-ID: 1B840C0000 at 10.249.0.6
>> Via: SIP/2.0/UDP 10.249.224.18:5060;branch=z9hG4bKl2olcr10e0khva0832o1.1
>> CSeq: 1 INVITE
>> ---------------------------
>> Hope we can get some info out of it.
>>
>> @ Mark,
>> i'm having provide check on it.
>>
>> I tried a cube but a different error came up.
>> 403 or 500 something. Maybe something's wrong on my cube configuration. Will
>> reconfigure the cube again and try it out.
>>
>> Thanks,
>> Jeff
>>
>>
>>
>>
>> On Wed, Mar 10, 2010 at 12:08 AM, Mark Holloway <mh at markholloway.com> wrote:
>>>
>>> Two things catch my attention.
>>>
>>> 1) The Request URI and the To header are different.  The To header is
>>> prepended with two extra digits and the host port is 5061.  The Request URI
>>> does not contain the digits 02 and the host port is 5060 as opposed to 5061.
>>>
>>> 2) The format of the SDP looks odd.  I'm not suggesting it's wrong, but
>>> that is not how I typically see the SDP formatted.  I recently experienced
>>> an issue where an IAD was rejecting media establishment due to an
>>> unsupported SDP parameter being sent by a Toshiba CIX using a SIP Trunk.  It
>>> is possible that UCM does not like something in the SDP.
>>>
>>> Is the SBC managed by you or your provider?  Do you have the ability to
>>> test your CCM SIP Trunk with CUBE?
>>>
>>> If I were you I would focus on the Request URI vs. To header first and see
>>> if that clear up your problem.
>>>
>>> On Mar 9, 2010, at 5:55 AM, Jefflin Choi wrote:
>>>
>>> > Hi,
>>> >
>>> > I'm trying to troubleshoot and incoming call from SBC to CCM SIP trunk.
>>> > Outgoing call to SBC from IP Phone works fine. using G711ulaw codec without
>>> > security.
>>> >
>>> > Topology:
>>> > SIP server ------------SBC(SIP)---------CCM7-----IP Phone(SCCP)
>>> >
>>> > Problem
>>> > I'm getting 400 Bad request from Sniffer trace. I checked my Partition
>>> > and CSS including transformation mask and saw no problem.
>>> > We are using UDP for sip protocol.
>>> >
>>> > Q.
>>> > Any idea why CCM7 is sending 400 Bad request? There seem to be a reason
>>> > CCM7 is rejecting the SIP invite however i could not find it.
>>> >
>>> > Attached is the captured sniffer trace on CCM.
>>> >
>>> > Thanks in advance for the help.
>>> >
>>> > regards,
>>> > Jeff
>>> >
>>> >
>>> >
>>> >
>>> >
>>> >
>>> > <sip invite 400 bad
>>> > request.pcap>_______________________________________________
>>> > cisco-voip mailing list
>>> > cisco-voip at puck.nether.net
>>> > https://puck.nether.net/mailman/listinfo/cisco-voip
>>>
>>
>> <pldtdemo_CiscoCallManager_sdi_2010-03-10_10-21-35.zip><pldtdemo_CiscoCallManager_sdl_2010-03-10_10-21-35.zip>_______________________________________________
>> cisco-voip mailing list
>> cisco-voip at puck.nether.net
>> https://puck.nether.net/mailman/listinfo/cisco-voip
>>
>>
>> _______________________________________________
>> cisco-voip mailing list
>> cisco-voip at puck.nether.net
>> https://puck.nether.net/mailman/listinfo/cisco-voip
>>
>>
>