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-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:gsma: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-dbe2-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-42a6-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/reg-data > (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=z9hG4bKPjPGEgPYOdx8sxqUOtzHyhPqE2fRbIoV3i > Via: SIP/2.0/TCP > xxx.xxx.xxx.101:5510;received=xxx.xxx.xxx.101;branch=z9hG4bK97cdab82-dbe2-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:gsma: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;term-ioi=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
