Hi Alan, Trey, We've found the problem behind this, and I've raised a github issue to track it (https://github.com/Metaswitch/sprout/issues/659). There should be a fix going in shortly.
Ellie -----Original Message----- From: [email protected] [mailto:[email protected]] On Behalf Of Kwon, Alan Sent: 17 July 2014 20:54 To: [email protected] Subject: Re: [Clearwater] Sprout stripping sdp of msrp request. Hi Ellie, I didn't see the Jet Set Radio release. so I just upgraded to it, re-ran the test. Still dropping the body. Thanks, Alan On 7/17/14, 2:40 PM, "Kwon, Alan" <[email protected]> wrote: >Hi Ellie, > > >I¹m running Halo release and seeing same problem. I¹m using Bono-Sprout >and Bono is dropping the entire message body. >The following is the Bono log: > > >17-07-2014 19:00:05.589 Verbose stack.cpp:226: RX 1914 bytes Request >msg >INVITE/cseq=4940 (rdata0x7fdc800095d8) from TCP 172.25.50.89:35661: >--start msg-- > >INVITE sip:[email protected];user=phone SIP/2.0 >Via: SIP/2.0/TCP >172.25.50.89:35661;rport;branch=z9hG4bKPjHXFBomZzfLtSiTJ25F4bUmEtyG8eis >tc >Max-Forwards: 70 >From: ><sip:[email protected]>;tag=kD7R1hWDQrGWStA--oPPRUo7yufIyQss >To: <sip:[email protected];user=phone> >Contact: ><sip:[email protected]:35661;transport=TCP;ob>;+g.oma.sip-im;+sip. >i >nstance="<urn:gsma:imei:35526604-120549-1>" >Call-ID: ZO0AqWgUuyKcalQLnZDKSvrjmPZvyZUC >CSeq: 4940 INVITE >Route: <sip:10.12.92.96:5060;transport=tcp;lr> >Route: <sip:sprout.cwims.iot1.com:5054;transport=TCP;lr;orig> >Allow: PRACK, INFO, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, >NOTIFY, REFER, MESSAGE, OPTIONS >Supported: replaces, 100rel, timer, norefersub >Session-Expires: 1800 >Min-SE: 90 >Accept-Contact: *;+g.oma.sip-im >Contribution-ID: sgcLaIlwoaelbE6YRLeL0phLqNAKHhzgDYAe >Subject: Yooo >User-Agent: IM-client/OMA1.0 sams/crespo-4.1.1 RCSAndrd/2.4.13 >COMLib/3.4.12 >P-Preferred-Identity: <sip:[email protected]> >Content-Type: multipart/mixed;boundary="boundary22" >Content-Length: 818 > >--boundary22 >Content-Type: application/sdp > >v=0 >o=- 3614612405 3614612405 IN IP4 172.25.50.89 s= c=IN IP4 172.25.50.89 >t=0 0 >m=message 9 TCP/MSRP * >a=setup:active >a=accept-types:application/im-iscomposing+xml message/cpim >a=path:msrp://172.25.50.89:9/Zz3A5NGrrX;tcp >a=sendrecv >a=accept-wrapped-types:message/imdn+xml text/plain >application/vnd.gsma.rcspushlocation+xml >application/vnd.gsma.rcs-ft-http+xml > >--boundary22 >Content-Type: message/cpim > >From: <sip:[email protected]> >To: <sip:[email protected]> >DateTime: 2014-07-17T14:00:05.568-05:00 >NS: imdn <urn:ietf:params:imdn> >imdn.Message-ID: QGEBQ4dGkYU1LcMI93Evs5DpONik3zrk >imdn.Disposition-Notification: positive-delivery, display > >Content-Type: text/plain;charset=utf-8 >Content-Length: 4 > >Yooo > >--boundary22-- > >--end msg-- >17-07-2014 19:00:05.589 Debug stack.cpp:410: Queuing cloned received >message 0x7fdc8004e598 for worker threads >17-07-2014 19:00:05.589 Debug stack.cpp:189: Worker thread dequeue >message >0x7fdc8004e598 >17-07-2014 19:00:05.589 Debug pjsip: sip_endpoint.c Distributing rdata >to >modules: Request msg INVITE/cseq=4940 (rdata0x7fdc8004e598) >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:257: Proxy RX request >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:900: Request received >on non-trusted port 5060 >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:1140: Perform access >proxy routing for INVITE request >17-07-2014 19:00:05.589 Debug pjutils.cpp:481: Found Route header, URI >= sip:10.12.92.96:5060;transport=tcp;lr >17-07-2014 19:00:05.589 Debug pjutils.cpp:484: Route header is local >17-07-2014 19:00:05.589 Debug pjutils.cpp:481: Found Route header, URI >= sip:sprout.cwims.iot1.com:5054;transport=TCP;lr;orig >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:1259: Message received >on non-trusted port 5060 >17-07-2014 19:00:05.589 Debug flowtable.cpp:137: Find flow for >transport >tcps0x7fdc800092e8 (2), remote address 172.25.50.89:35661 >17-07-2014 19:00:05.589 Debug flowtable.cpp:575: Dialog count now 2 for >flow sip:[email protected] >17-07-2014 19:00:05.589 Debug flowtable.cpp:151: Found flow record >0x7fdc78003e80 >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:1295: Message received >on known client flow >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:1326: Request has one >P-Preferred-Identity >17-07-2014 19:00:05.589 Debug pjutils.cpp:446: Adding >P-Asserted-Identity >header: <sip:[email protected]> >17-07-2014 19:00:05.589 Debug pjutils.cpp:481: Found Route header, URI >= sip:10.12.92.96:5060;transport=tcp;lr >17-07-2014 19:00:05.589 Debug pjutils.cpp:484: Route header is local >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:1620: Top Route header >is local - erasing >17-07-2014 19:00:05.589 Debug pjutils.cpp:463: Next hop node is encoded >in top route header >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:1490: Add record route >header(s) >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:1495: Message received >from client - double Record-Route >17-07-2014 19:00:05.589 Debug pjutils.cpp:521: Added Record-Route >header, URI = sip:[email protected]:5060;transport=TCP;lr >17-07-2014 19:00:05.589 Debug pjutils.cpp:521: Added Record-Route >header, URI = sip:10.12.92.96:5058;transport=TCP;lr >17-07-2014 19:00:05.589 Debug flowtable.cpp:592: Dialog count now 1 for >flow sip:[email protected] >17-07-2014 19:00:05.589 Debug acr.cpp:48: Created ACR (0x7fdc780009b0) >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:593: Trust mode >INBOUND_EDGE_CLIENT(,-rsp,-pch), serving state None >17-07-2014 19:00:05.589 Debug pjsip: tsx0x7fdc78000 Transaction created >for Request msg INVITE/cseq=4940 (rdata0x7fdc8004e598) >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:2147: UASTransaction >constructor (0x7fdc78001650) >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:2148: ACR >(0x7fdc780009b0) >17-07-2014 19:00:05.589 Debug pjsip: tsx0x7fdc78000 Incoming Request >msg >INVITE/cseq=4940 (rdata0x7fdc8004e598) in state Null >17-07-2014 19:00:05.589 Debug pjsip: tsx0x7fdc78000 State changed from >Null to Trying, event=RX_MSG >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:365: tsx0x7fdc78000ee8 >- tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying >17-07-2014 19:00:05.589 Debug pjsip: endpoint Response msg >408/INVITE/cseq=4940 (tdta0x7fdc78005090) created >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:3582: Report SAS start >marker - trail (10ba0) >17-07-2014 19:00:05.589 Debug trustboundary.cpp:67: Add P-Charging >headers >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:3681: Allocating >transaction and data for target 0 >17-07-2014 19:00:05.589 Debug pjsip: tsx0x7fdc78009 Transaction created >for Request msg INVITE/cseq=4940 (tdta0x7fdc78006330) >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:3701: Adding trail >identifier 68512 to UAC transaction >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:3720: Updating request >URI and route for target 0 >17-07-2014 19:00:05.589 Debug stateful_proxy.cpp:4154: Resolve next hop >destination >17-07-2014 19:00:05.589 Debug pjutils.cpp:463: Next hop node is encoded >in top route header >17-07-2014 19:00:05.589 Debug sipresolver.cpp:85: SIPResolver::resolve >for name sprout.cwims.iot1.com, port 5054, transport 6, family 2 >17-07-2014 19:00:05.589 Debug baseresolver.cpp:480: Attempt to parse >sprout.cwims.iot1.com as IP address >17-07-2014 19:00:05.589 Debug sipresolver.cpp:127: Port is specified >17-07-2014 19:00:05.589 Debug sipresolver.cpp:295: Perform A/AAAA >record lookup only, name = sprout.cwims.iot1.com >17-07-2014 19:00:05.589 Debug dnscachedresolver.cpp:179: Pulling 2 >records from cache for sprout.cwims.iot1.com A >17-07-2014 19:00:05.589 Debug baseresolver.cpp:359: Found 2 A/AAAA >records, randomizing >17-07-2014 19:00:05.590 Debug baseresolver.cpp:380: Added a server, now >have 1 of 5 >17-07-2014 19:00:05.590 Debug baseresolver.cpp:380: Added a server, now >have 2 of 5 >17-07-2014 19:00:05.590 Debug baseresolver.cpp:418: Adding 0 servers >from blacklist >17-07-2014 19:00:05.590 Info pjutils.cpp:734: Resolved destination URI >sip:sprout.cwims.iot1.com:5054;transport=TCP;lr;orig to 2 servers >17-07-2014 19:00:05.590 Debug stateful_proxy.cpp:4192: Sending request >for sip:[email protected];user=phone >17-07-2014 19:00:05.590 Debug pjsip: tsx0x7fdc78009 Sending Request msg >INVITE/cseq=4940 (tdta0x7fdc78006330) in state Null >17-07-2014 19:00:05.590 Debug pjsip: endpoint Request msg >INVITE/cseq=4940 (tdta0x7fdc78006330): skipping target resolution >because address is already set >17-07-2014 19:00:05.590 Verbose stack.cpp:242: TX 1239 bytes Request >msg >INVITE/cseq=4940 (tdta0x7fdc78006330) to TCP 10.12.92.97:5054: >--start msg-- > >INVITE sip:[email protected];user=phone SIP/2.0 >Record-Route: <sip:10.12.92.96:5058;transport=TCP;lr> >Record-Route: ><sip:[email protected]:5060;transport=TCP;lr> >Via: SIP/2.0/TCP >10.12.92.96:38415;rport;branch=z9hG4bKPjpcZhGxv4aJbYuxRJ1j6nmCH9t-EfPfj >2 >Via: SIP/2.0/TCP >172.25.50.89:35661;rport=35661;received=172.25.50.89;branch=z9hG4bKPjHX >FBo >m >ZzfLtSiTJ25F4bUmEtyG8eistc >Max-Forwards: 69 >From: ><sip:[email protected]>;tag=kD7R1hWDQrGWStA--oPPRUo7yufIyQss >To: <sip:[email protected];user=phone> >Contact: ><sip:[email protected]:35661;transport=TCP;ob>;+g.oma.sip-im;+sip. >i >nstance="<urn:gsma:imei:35526604-120549-1>" >Call-ID: ZO0AqWgUuyKcalQLnZDKSvrjmPZvyZUC >CSeq: 4940 INVITE >Route: <sip:sprout.cwims.iot1.com:5054;transport=TCP;lr;orig> >Allow: PRACK, INFO, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, >NOTIFY, REFER, MESSAGE, OPTIONS >Supported: replaces, 100rel, timer, norefersub >Session-Expires: 600 >Min-SE: 90 >Accept-Contact: *;+g.oma.sip-im >Contribution-ID: sgcLaIlwoaelbE6YRLeL0phLqNAKHhzgDYAe >Subject: Yooo >User-Agent: IM-client/OMA1.0 sams/crespo-4.1.1 RCSAndrd/2.4.13 >COMLib/3.4.12 >P-Asserted-Identity: <sip:[email protected]> >Content-Length: 0 > > >--end msg-- > > > > > > > >There¹s nothing in the log regarding the parsing of Multipart-Body, but >I suspect it¹s related to these corrections made in Halo release: > * Incorrect multipart boundary handling in bono/sprout >(https://github.com/Metaswitch/sprout/issues/447) > * bono/sprout duplicate part headers on multipart content >(https://github.com/Metaswitch/sprout/issues/446) > > >I can¹t get any traffic going across with this problem. Any idea when >this will be addressed? > >Thank you, >Alan > > >On 7/11/14, 1:55 PM, "Ormsbee, Trey" ><[email protected]> wrote: > >>Thank you, If you need further information or someone to test >>anything please let me know. >> >>Thanks >>Trey >> >>On Jul 11, 2014, at 12:52 PM, Eleanor Merry >><[email protected]> wrote: >> >>> Hi Trey, >>> >>> Thanks for raising this - we're investigating it now. >>> >>> Ellie >>> >>> -----Original Message----- >>> From: [email protected] >>>[mailto:[email protected]] On Behalf Of >>>Ormsbee, Trey >>> Sent: 10 July 2014 19:40 >>> To: [email protected] >>> Subject: [Clearwater] Sprout stripping sdp of msrp request. >>> >>> I am seeing an issue with sprout removing the sdp of a sip message >>>that was received with an msrp sdp. In this case it is an INVITE >>>that sprout passed on to our application server that includes the >>>sdp, when passed back from the application server the sdp is still >>>there. But when forwarding back out to the recipient the sdp is gone. >>>Nothing in the >>>logs stands out. Here is a sanitized excerpt from the log starting >>>from the received INVITE from the application server.. If needed I >>>can attach more of the log. >>> >>> >>> 10-07-2014 16:44:56.943 Debug stack.cpp:410: Queuing cloned received >>>message 0x7ff93035a8c8 for worker threads >>> 10-07-2014 16:44:56.943 Debug stack.cpp:189: Worker thread dequeue >>>message 0x7ff93035a8c8 >>> 10-07-2014 16:44:56.943 Debug pjsip: sip_endpoint.c Distributing >>>rdata to modules: Response msg 100/INVITE/cseq=16363 >>>(rdata0x7ff93035a8c8) >>> 10-07-2014 16:44:56.943 Debug pjsip: tsx0x7ff9202b0 Incoming >>>Response msg 100/INVITE/cseq=16363 (rdata0x7ff93035a8c8) in state >>>Calling >>> 10-07-2014 16:44:56.943 Debug pjsip: tsx0x7ff9202b0 State changed >>>from Calling to Proceeding, event=RX_MSG >>> 10-07-2014 16:44:56.943 Debug stateful_proxy.cpp:365: >>>tsx0x7ff9202b0da8 >>>- tu_on_tsx_state UAC, TSX_STATE RX_MSG state=Proceeding >>> 10-07-2014 16:44:56.943 Debug stateful_proxy.cpp:4295: >>>tsx0x7ff9202b0da8 - uac_data = 0x7ff9202b8fb0, uas_data = >>>0x7ff92019bd30 >>> 10-07-2014 16:44:56.943 Debug stateful_proxy.cpp:4334: >>>tsx0x7ff9202b0da8 - RX_MSG on active UAC transaction >>> 10-07-2014 16:44:56.943 Debug stateful_proxy.cpp:3133: >>>tsx0x7ff9202b0da8 - Discard 100/INVITE response >>> 10-07-2014 16:44:56.943 Debug stack.cpp:191: Worker thread completed >>>processing message 0x7ff93035a8c8 >>> 10-07-2014 16:44:56.943 Debug stack.cpp:197: Request latency = 325us >>> 10-07-2014 16:44:56.943 Debug pjsip: sip_endpoint.c Processing >>>incoming >>>message: Request msg INVITE/cseq=1 (rdata0x7ff9300369b8) >>> 10-07-2014 16:44:56.943 Verbose stack.cpp:226: RX 1898 bytes Request >>>msg INVITE/cseq=1 (rdata0x7ff9300369b8) from TCP xxx.xxx.xxx.101:45311: >>> --start msg-- >>> >>> INVITE sip:[email protected];user=phone SIP/2.0 >>> Via: SIP/2.0/TCP >>>xxx.xxx.xxx.101:5510;branch=z9hG4bK97cdab82-dbe2-42a6-92c7-4db45587fa >>>2d >>> From: >>><sip:[email protected]>;tag=18d3e679-45cd-470b-9bd4-ec43e8dfbf78 >>> To: <sip:[email protected];user=phone> >>> Call-ID: c1855804-1075-4053-9047-b7c869c24ae0 >>> CSeq: 1 INVITE >>> Contact: >>><sip:[email protected]:5510>;+g.oma.sip-im;+sip.instance="<urn: >>>gsm >>>a >>>:imei:35513605-331763-5>" >>> Accept-Contact: *;+g.oma.sip-im >>> Allow: >>>INVITE,ACK,CANCEL,BYE,UPDATE,REFER,SUBSCRIBE,MESSAGE,REGISTER,INFO >>> User-Agent: IM-serv/OMA1.0 CustomEntry-RMS/2.0 >>> Supported: timer,gruu >>> Session-Expires: 400;refresher=uas >>> Min-SE: 400 >>> P-Asserted-Identity: <sip:[email protected]> >>> Subject: Xjckvkvk >>> Contribution-ID: WtNdhjExDY8aqwiQ8ffTo0k4rsnlnI1LsLZD >>> Content-Type: multipart/mixed;boundary="gc0p4Jq0M2Yt08j34c0p" >>> P-Charging-Vector: >>>icid-value="30fdc0efc89051a5a2de485d92166e5a";orig-ioi=example.com >>> Content-Length: 896 >>> Max-Forwards: 70 >>> >>> >>> --gc0p4Jq0M2Yt08j34c0p >>> Content-Type: message/cpim >>> >>> From: <sip:[email protected]> >>> To: <sip:[email protected]> >>> DateTime: 2014-07-10T16:44:56Z >>> NS: imdn <urn:ietf:params:imdn> >>> imdn.Message-ID: 74MgSGNuCflRXJtHR2qWTz7vUlCcqlsG >>> imdn.Disposition-Notification: positive-delivery, display >>> >>> Content-Type: text/plain;charset=utf-8 >>> Content-Length: 8 >>> >>> Xjckvkvk >>> --gc0p4Jq0M2Yt08j34c0p >>> Content-Type: application/sdp >>> >>> v=0 >>> o=- 15522009643326747650 15522009643326773420 IN IP4 >>>media.example.com >>> s=- >>> c=IN IP4 media.example.com >>> t=0 0 >>> m=message 9000 TCP/MSRP * >>> a=accept-types:application/im-iscomposing+xml message/cpim >>>a=accept-wrapped-types:message/imdn+xml text/plain >>>application/vnd.gsma.rcspushlocation+xml >>>application/vnd.gsma.rcs-ft-http+xml >>> a=sendrecv >>> a=path:msrp://media.example.com:9000/UHjL9kLC;tcp >>> a=setup:actpass >>> >>> --gc0p4Jq0M2Yt08j34c0p-- >>> --end msg-- >>> 10-07-2014 16:44:56.943 Debug stack.cpp:410: Queuing cloned received >>>message 0x7ff93035a8c8 for worker threads >>> 10-07-2014 16:44:56.943 Debug stack.cpp:189: Worker thread dequeue >>>message 0x7ff93035a8c8 >>> 10-07-2014 16:44:56.943 Debug pjsip: sip_endpoint.c Distributing >>>rdata to modules: Request msg INVITE/cseq=1 (rdata0x7ff93035a8c8) >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:257: Proxy RX >>>request >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:450: Initial (not >>>in-dialog) request for routing proxy >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:501: No Route >>>header, so treat as terminating request >>> 10-07-2014 16:44:56.944 Debug acr.cpp:48: Created ACR >>>(0x7ff93025ab80) >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:593: Trust mode >>>TRUSTED(,,), serving state term (new) >>> 10-07-2014 16:44:56.944 Debug pjsip: tsx0x7ff930003 Transaction >>>created for Request msg INVITE/cseq=1 (rdata0x7ff93035a8c8) >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:2143: >>>UASTransaction constructor (0x7ff9302cd260) >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:2144: ACR >>>(0x7ff93025ab80) >>> 10-07-2014 16:44:56.944 Debug pjsip: tsx0x7ff930003 Incoming Request >>>msg INVITE/cseq=1 (rdata0x7ff93035a8c8) in state Null >>> 10-07-2014 16:44:56.944 Debug pjsip: tsx0x7ff930003 State changed >>>from Null to Trying, event=RX_MSG >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:365: >>>tsx0x7ff930003858 >>>- tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying >>> 10-07-2014 16:44:56.944 Debug pjsip: endpoint Response msg >>>408/INVITE/cseq=1 (tdta0x7ff9300ed0d0) created >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:3578: Report SAS >>>start marker - trail (b764b) >>> 10-07-2014 16:44:56.944 Debug pjsip: tsx0x7ff930003 Sending Response >>>msg 100/INVITE/cseq=1 (tdta0x7ff930354390) in state Trying >>> 10-07-2014 16:44:56.944 Verbose stack.cpp:242: TX 395 bytes Response >>>msg 100/INVITE/cseq=1 (tdta0x7ff930354390) to TCP xxx.xxx.xxx.101:45311: >>> --start msg-- >>> >>> SIP/2.0 100 Trying >>> Via: SIP/2.0/TCP >>>xxx.xxx.xxx.101:5510;received=xxx.xxx.xxx.101;branch=z9hG4bK97cdab82- >>>dbe >>>2 >>>-42a6-92c7-4db45587fa2d >>> Call-ID: c1855804-1075-4053-9047-b7c869c24ae0 >>> From: >>><sip:[email protected]>;tag=18d3e679-45cd-470b-9bd4-ec43e8dfbf78 >>> To: >>><sip:[email protected];user=phone>;tag=z9hG4bK97cdab82-dbe2-4 >>>2a6 >>>- >>>92c7-4db45587fa2d >>> CSeq: 1 INVITE >>> Content-Length: 0 >>> >>> >>> --end msg-- >>> 10-07-2014 16:44:56.944 Debug pjsip: tsx0x7ff930003 State changed >>>from Trying to Proceeding, event=TX_MSG >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:365: >>>tsx0x7ff930003858 >>>- tu_on_tsx_state UAS, TSX_STATE TX_MSG state=Proceeding >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:2713: Looking for >>>AS chain for incoming transaction request, serving state = term (new) >>> 10-07-2014 16:44:56.944 Debug pjutils.cpp:219: aor_from_uri >>>converted sip:[email protected];user=phone to >>>sip:[email protected] >>> 10-07-2014 16:44:56.944 Debug stateful_proxy.cpp:2770: Looking up >>>iFCs for sip:[email protected] for new AS chain >>> 10-07-2014 16:44:56.945 Debug hssconnection.cpp:367: Making >>>Homestead request for >>>/impu/sip%3A%2B155555550001%40example.com/reg-data >>> 10-07-2014 16:44:56.945 Debug httpconnection.cpp:467: Sending HTTP >>>request : >>>http://xxx.xxx.xxx.51:8888/impu/sip%3A%2B155555550001%40example.com/r >>>eg- >>>d >>>ata (try 0) on new connection >>> 10-07-2014 16:44:56.947 Debug httpconnection.cpp:751: Received >>>header http/1.1200ok with value >>> 10-07-2014 16:44:56.947 Debug httpconnection.cpp:751: Received >>>header content-length with value 2293 >>> 10-07-2014 16:44:56.947 Debug httpconnection.cpp:751: Received >>>header content-type with value text/plain >>> 10-07-2014 16:44:56.947 Debug httpconnection.cpp:751: Received >>>header with value >>> 10-07-2014 16:44:56.947 Debug httpconnection.cpp:478: Received HTTP >>>response : <ClearwaterRegData> >>> <RegistrationState>REGISTERED</RegistrationState> >>> <IMSSubscription xsi="http://www.w3.org/2001/XMLSchema-instance"; >>>noNamespaceSchemaLocation="CxDataType.xsd"> >>> <PrivateID>[email protected]</PrivateID> >>> <ServiceProfile> >>> <PublicIdentity> >>> >>><Identity>sip:[email protected]</Identity> >>> </PublicIdentity> >>> <InitialFilterCriteria> >>> <Priority>0</Priority> >>> <TriggerPoint> >>> >>><ConditionTypeCNF>0</ConditionTypeCNF> >>> <SPT> >>> >>><ConditionNegated>0</ConditionNegated> >>> <Group>0</Group> >>> <Method>INVITE</Method> >>> </SPT> >>> <SPT> >>> >>><ConditionNegated>1</ConditionNegated> >>> <Group>0</Group> >>> <SIPHeader> >>> >>><Header>User-Agent</Header> >>> >>><Content>CustomEntry</Content> >>> </SIPHeader> >>> </SPT> >>> <SPT> >>> >>><ConditionNegated>1</ConditionNegated> >>> <Group>0</Group> >>> <SessionDescription> >>> >>><Line>m</Line> >>> >>><Content>.*[Rr][Tt][Pp]</Content> >>> </SessionDescription> >>> </SPT> >>> <SPT> >>> >>><ConditionNegated>0</ConditionNegated> >>> <Group>1</Group> >>> <Method>MESSAGE</Method> >>> </SPT> >>> <SPT> >>> >>><ConditionNegated>1</ConditionNegated> >>> <Group>1</Group> >>> <SIPHeader> >>> >>><Header>User-Agent</Header> >>> >>><Content>CustomEntry</Content> >>> </SIPHeader> >>> </SPT> >>> </TriggerPoint> >>> <ApplicationServer> >>> >>><ServerName>sip:xxx.xxx.xxx.101:5510</ServerName> >>> >>><DefaultHandling>1</DefaultHandling> >>> </ApplicationServer> >>> </InitialFilterCriteria> >>> <InitialFilterCriteria> >>> <Priority>1</Priority> >>> <TriggerPoint> >>> >>><ConditionTypeCNF>0</ConditionTypeCNF> >>> <SPT> >>> >>><ConditionNegated>0</ConditionNegated> >>> <Group>2</Group> >>> >>><Method>REGISTER</Method> >>> <Extension> >>> >>><RegistrationType>0</RegistrationType> >>> </Extension> >>> </SPT> >>> <SPT> >>> >>><ConditionNegated>0</ConditionNegated> >>> <Group>3</Group> >>> >>><Method>REGISTER</Method> >>> <Extension> >>> >>><RegistrationType>1</RegistrationType> >>> </Extension> >>> </SPT> >>> </TriggerPoint> >>> <ApplicationServer> >>> >>><ServerName>sip:xxx.xxx.xxx.101:5510</ServerName> >>> >>><DefaultHandling>1</DefaultHandling> >>> </ApplicationServer> >>> </InitialFilterCriteria> >>> </ServiceProfile> >>> </IMSSubscription> >>> </ClearwaterRegData> >>> >>> >>> 10-07-2014 16:44:56.947 Debug hssconnection.cpp:293: Processing >>>Identity node from HSS XML - sip:[email protected] >>> >>> 10-07-2014 16:44:56.947 Debug stateful_proxy.cpp:2774: Successfully >>>looked up iFCs >>> 10-07-2014 16:44:56.947 Debug aschain.cpp:74: Creating AsChain >>>0x7ff930155890 with 2 IFC and adding to map >>> 10-07-2014 16:44:56.947 Debug aschain.cpp:76: Attached ACR >>>(0x7ff93025ab80) to chain >>> 10-07-2014 16:44:56.947 Debug stateful_proxy.cpp:4954: >>>UASTransaction >>>0x7ff9302cd260 linked to AsChain AsChain-term[0x7ff930155890]:1/2 >>> 10-07-2014 16:44:56.947 Debug stateful_proxy.cpp:2654: Terminating >>>half >>> 10-07-2014 16:44:56.947 Debug stateful_proxy.cpp:2926: Apply >>>terminating services >>> 10-07-2014 16:44:56.948 Debug ifchandler.cpp:476: SPT class Method: >>>result true >>> 10-07-2014 16:44:56.948 Debug ifchandler.cpp:583: Add to group 0 val >>>true >>> 10-07-2014 16:44:56.948 Debug ifchandler.cpp:476: SPT class SIPHeader: >>>result true >>> 10-07-2014 16:44:56.948 Debug ifchandler.cpp:583: Add to group 0 val >>>false >>> 10-07-2014 16:44:56.948 Debug ifchandler.cpp:476: SPT class >>>SessionDescription: result false >>> 10-07-2014 16:44:56.948 Debug ifchandler.cpp:583: Add to group 0 val >>>true >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:476: SPT class Method: >>>result false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:583: Add to group 1 val >>>false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:476: SPT class SIPHeader: >>>result true >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:583: Add to group 1 val >>>false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:601: Result group 0 val >>>false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:601: Result group 1 val >>>false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:605: iFC does not match >>> 10-07-2014 16:44:56.949 Debug aschain.cpp:217: No match for >>>AsChain-term[0x7ff930155890]:1/2 >>> 10-07-2014 16:44:56.949 Debug stateful_proxy.cpp:2981: Done internal >>>step - advance link to AsChain-term[0x7ff930155890]:2/2 and go around >>>again >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:476: SPT class Method: >>>result false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:583: Add to group 2 val >>>false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:476: SPT class Method: >>>result false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:583: Add to group 3 val >>>false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:601: Result group 2 val >>>false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:601: Result group 3 val >>>false >>> 10-07-2014 16:44:56.949 Debug ifchandler.cpp:605: iFC does not match >>> 10-07-2014 16:44:56.949 Debug aschain.cpp:217: No match for >>>AsChain-term[0x7ff930155890]:2/2 >>> 10-07-2014 16:44:56.949 Debug stateful_proxy.cpp:2981: Done internal >>>step - advance link to AsChain-term[0x7ff930155890]:3/2 and go around >>>again >>> 10-07-2014 16:44:56.949 Debug aschain.cpp:206: No ASs left in chain >>> 10-07-2014 16:44:56.949 Info stateful_proxy.cpp:2929: Terminating >>>services disposition 2 >>> 10-07-2014 16:44:56.949 Debug stateful_proxy.cpp:2663: Single >>>Record-Route - end of terminating handling >>> 10-07-2014 16:44:56.949 Debug pjutils.cpp:219: aor_from_uri >>>converted sip:[email protected];user=phone to >>>sip:[email protected] >>> 10-07-2014 16:44:56.949 Info stateful_proxy.cpp:1869: Look up >>>targets in registration store: sip:[email protected] >>> 10-07-2014 16:44:56.949 Debug regstore.cpp:102: Get AoR data for >>>sip:[email protected] >>> 10-07-2014 16:44:56.949 Debug memcachedstore.cpp:260: Key >>>reg\\sip:[email protected] hashes to vbucket 88 via hash >>>0xf1e7f0d8 >>> 10-07-2014 16:44:56.949 Debug memcachedstore.cpp:304: 1 read >>>replicas for key reg\\sip:[email protected] >>> 10-07-2014 16:44:56.949 Debug memcachedstore.cpp:337: Attempt to >>>read from replica 0 (connection 0x7ff9302d2950) >>> 10-07-2014 16:44:56.949 Debug memcachedstore.cpp:343: Fetch result >>> 10-07-2014 16:44:56.949 Debug memcachedstore.cpp:351: Found record >>>on replica 0 >>> 10-07-2014 16:44:56.949 Debug memcachedstore.cpp:400: Read 651 bytes >>>from table reg key sip:[email protected], CAS = 104680 >>> 10-07-2014 16:44:56.949 Debug regstore.cpp:455: Deserialize 1 bindings >>> 10-07-2014 16:44:56.949 Debug regstore.cpp:462: Binding >>><urn:gsma:imei:35912505-094305-1>:1 >>> 10-07-2014 16:44:56.949 Debug regstore.cpp:488: Deserialize 1 path >>>headers >>> 10-07-2014 16:44:56.949 Debug regstore.cpp:494: Deserialized path >>>header <sip:xxx.xxx.xxx.40:5060;lr> >>> 10-07-2014 16:44:56.949 Debug regstore.cpp:503: Deserialize 0 >>>subscriptions >>> 10-07-2014 16:44:56.949 Debug regstore.cpp:114: Data store returned >>>a record, CAS = 104680 >>> 10-07-2014 16:44:56.949 Debug stateful_proxy.cpp:1926: Target = >>><sip:[email protected]:46670;transport=TCP;ob> >>> 10-07-2014 16:44:56.949 Debug stateful_proxy.cpp:3677: Allocating >>>transaction and data for target 0 >>> 10-07-2014 16:44:56.950 Debug pjsip: tsx0x7ff9300df Transaction >>>created for Request msg INVITE/cseq=1 (tdta0x7ff930358290) >>> 10-07-2014 16:44:56.950 Debug stateful_proxy.cpp:3697: Adding trail >>>identifier 751179 to UAC transaction >>> 10-07-2014 16:44:56.950 Debug stateful_proxy.cpp:3716: Updating >>>request URI and route for target 0 >>> 10-07-2014 16:44:56.950 Debug pjutils.cpp:219: aor_from_uri >>>converted sip:[email protected];user=phone to >>>sip:[email protected] >>> 10-07-2014 16:44:56.950 Debug stateful_proxy.cpp:4112: Adding a >>>Route header to sip:xxx.xxx.xxx.40:5060;transport= >>> 10-07-2014 16:44:56.950 Debug stateful_proxy.cpp:4122: Target came >>>from store, storing AoR = sip:[email protected], binding_id = >>><urn:gsma:imei:35912505-094305-1>:1 >>> 10-07-2014 16:44:56.950 Debug stateful_proxy.cpp:4150: Resolve next >>>hop destination >>> 10-07-2014 16:44:56.950 Debug pjutils.cpp:463: Next hop node is >>>encoded in top route header >>> 10-07-2014 16:44:56.950 Debug sipresolver.cpp:85: >>>SIPResolver::resolve for name xxx.xxx.xxx.40, port 5060, transport >>>-1, family 2 >>> 10-07-2014 16:44:56.950 Debug baseresolver.cpp:480: Attempt to parse >>>xxx.xxx.xxx.40 as IP address >>> 10-07-2014 16:44:56.950 Debug sipresolver.cpp:102: Target is an IP >>>address - default port/transport if required >>> 10-07-2014 16:44:56.950 Info pjutils.cpp:734: Resolved destination >>>URI sip:xxx.xxx.xxx.40:5060;lr to 1 servers >>> 10-07-2014 16:44:56.950 Debug stateful_proxy.cpp:4188: Sending >>>request for sip:[email protected]:46670;transport=TCP;ob >>> 10-07-2014 16:44:56.950 Debug pjsip: tsx0x7ff9300df Sending Request >>>msg >>>INVITE/cseq=1 (tdta0x7ff930358290) in state Null >>> 10-07-2014 16:44:56.950 Debug pjsip: endpoint Request msg >>>INVITE/cseq=1 (tdta0x7ff930358290): skipping target resolution >>>because address is already set >>> 10-07-2014 16:44:56.950 Verbose stack.cpp:242: TX 1268 bytes Request >>>msg INVITE/cseq=1 (tdta0x7ff930358290) to UDP xxx.xxx.xxx.40:5060: >>> --start msg-- >>> >>> INVITE sip:[email protected]:46670;transport=TCP;ob SIP/2.0 >>> Record-Route: >>><sip:sprout01.example.com:5054;transport=TCP;lr;charge-term> >>> Via: SIP/2.0/UDP >>>xxx.xxx.xxx.41:5054;rport;branch=z9hG4bKPjPGEgPYOdx8sxqUOtzHyhPqE2fRb >>>IoV >>>3 >>>i >>> Via: SIP/2.0/TCP >>>xxx.xxx.xxx.101:5510;received=xxx.xxx.xxx.101;branch=z9hG4bK97cdab82- >>>dbe >>>2 >>>-42a6-92c7-4db45587fa2d >>> From: >>><sip:[email protected]>;tag=18d3e679-45cd-470b-9bd4-ec43e8dfbf78 >>> To: <sip:[email protected];user=phone> >>> Call-ID: c1855804-1075-4053-9047-b7c869c24ae0 >>> CSeq: 1 INVITE >>> Contact: >>><sip:[email protected]:5510>;+g.oma.sip-im;+sip.instance="<urn: >>>gsm >>>a >>>:imei:35513605-331763-5>" >>> Accept-Contact: *;+g.oma.sip-im >>> Allow: INVITE, ACK, CANCEL, BYE, UPDATE, REFER, SUBSCRIBE, MESSAGE, >>>REGISTER, INFO >>> User-Agent: IM-serv/OMA1.0 CustomEntry-RMS/2.0 >>> Supported: timer, gruu >>> Session-Expires: 600;refresher=uas >>> Min-SE: 400 >>> P-Asserted-Identity: <sip:[email protected]> >>> Subject: Xjckvkvk >>> Contribution-ID: WtNdhjExDY8aqwiQ8ffTo0k4rsnlnI1LsLZD >>> P-Charging-Vector: >>>icid-value="30fdc0efc89051a5a2de485d92166e5a";orig-ioi=example.com;te >>>rm- >>>i >>>oi=example.com >>> Max-Forwards: 69 >>> P-Called-Party-ID: <sip:[email protected]> >>> Route: <sip:xxx.xxx.xxx.40:5060;lr> >>> Content-Length: 0 >>> >>> >>> --end msg-- >>> >>> _______________________________________________ >>> Clearwater mailing list >>> [email protected] >>> http://lists.projectclearwater.org/listinfo/clearwater >> >>_______________________________________________ >>Clearwater mailing list >>[email protected] >>http://lists.projectclearwater.org/listinfo/clearwater > >_______________________________________________ >Clearwater mailing list >[email protected] >http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
