[cisco-voip] SIP 400 Bad request
Kevin Thorngren
kthorngr at cisco.com
Tue Mar 9 23:11:51 EST 2010
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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20100309/474334fd/attachment.html>
More information about the cisco-voip
mailing list