Hi Ellie, thanks for the answer. I checked and the contact header in the 180 ringing becomes actually the Request-URI in the PRACK and the contact header is of the following form: Contact <sip:numberOfTheCalledPart@ [int.sbc.ip.address];rinstance=83xxxx..;dtg=TG_PCSCF_INT_IP> This becomes the sip uri in the Prack (and this is actually making sense since we need to acknowledge a ringing received from the called part). Said that the SBC is a Sonus 5100. Please let me know your opinion or if you need additional information.
Thank you in advance, Abaco 2014-11-28 20:51 GMT+01:00 Eleanor Merry <[email protected]>: > Hi Abaco, > > > > I believe Sprout is behaving correctly. It receives a PRACK, and follows > the route set on it. It then sends the request to the Request URI, but the > terminating SBC rejects it. The RequestURI should have been set to the > Contact header on the 1xx response that generated the PRACK. > > > > This suggests that either the SBC that sends the 1xx response isn’t > correctly setting the Contact header to a value that will be accepted by > the SBC, or the SBC that sends on the PRACK isn’t correctly setting the > RequestURI to the received Contact header. What SBC are you using? > > > > Ellie > > > > *From:* Ruggero Schiavi [mailto:[email protected]] > *Sent:* 28 November 2014 08:00 > *To:* Eleanor Merry > *Cc:* [email protected] > *Subject:* Re: [Clearwater] PRACK PROBLEM > > > > HI Ellie, > > Thanks for your reply. > > As your requested here you can find the Sprout Log from the received Prack > to the Method not allowed message received by the SBC. > > Please let me know your opinion, > > Regards, > > Abaco > > 28-11-2014 07:37:57.804 UTC Verbose stack.cpp:239: RX 624 bytes Request > msg PRACK/cseq=286923527 (rdata0x20367e8) from UDP > [sbc.private.ip.address]:5060: > --start msg-- > > PRACK > sip:87100004@[sbc.private.ip.address]:5060;rinstance=ebdc3f2d5251207f;dtg=TG_PCSCF_INT_IP > SIP/2.0 > Via: SIP/2.0/UDP > [sbc.private.ip.address]:5060;branch=z9hG4bK0cB126c28029d093c55 > From: <sip:[email protected];pstn-params=9084818088;cpc=ordinary > >;tag=gK0c159f6a > To: <sip:[email protected]>;tag=gK049472a3 > Call-ID: 786540_132020356@[sbc.private.ip.address] > CSeq: 286923527 PRACK > Max-Forwards: 70 > Route: < > sip:ppsprout1.ims.prod.lan:5054;transport=TCP;lr;service=scscf;billing-role=charge-orig > > > Route: < > sip:ppsprout1.ims.prod.lan:5054;transport=TCP;lr;service=scscf;billing-role=charge-term > > > RAck: 2133018667 286923526 INVITE > Content-Length: 0 > > > --end msg-- > 28-11-2014 07:37:57.804 UTC Debug stack.cpp:465: Queuing cloned received > message 0x7fcf640ceb38 for worker threads > 28-11-2014 07:37:57.804 UTC Debug stack.cpp:202: Worker thread dequeue > message 0x7fcf640ceb38 > 28-11-2014 07:37:57.804 UTC Debug pjsip: sip_endpoint.c Distributing rdata > to modules: Request msg PRACK/cseq=286923527 (rdata0x7fcf640ceb38) > 28-11-2014 07:37:57.804 UTC Debug basicproxy.cpp:89: Process PRACK request > 28-11-2014 07:37:57.804 UTC Verbose sproutletproxy.cpp:455: Sproutlet > Proxy transaction (0x7fcf6c3cd410) created > 28-11-2014 07:37:57.804 UTC Debug basicproxy.cpp:1231: Report SAS start > marker - trail (1c0ed) > 28-11-2014 07:37:57.804 UTC Debug pjutils.cpp:1604: Logging SAS Call-ID > marker, Call-ID 786540_132020356@[sbc.private.ip.address] > 28-11-2014 07:37:57.804 UTC Debug pjutils.cpp:676: Cloned Request msg > PRACK/cseq=286923527 (rdata0x7fcf640ceb38) to tdta0x7fcf6c3d56d0 > 28-11-2014 07:37:57.804 UTC Debug pjsip: tsx0x7fcf6c477 Transaction > created for Request msg PRACK/cseq=286923527 (rdata0x7fcf640ceb38) > 28-11-2014 07:37:57.804 UTC Debug pjsip: tsx0x7fcf6c477 Incoming Request > msg PRACK/cseq=286923527 (rdata0x7fcf640ceb38) in state Null > 28-11-2014 07:37:57.804 UTC Debug pjsip: tsx0x7fcf6c477 State changed from > Null to Trying, event=RX_MSG > 28-11-2014 07:37:57.804 UTC Debug basicproxy.cpp:214: tsx0x7fcf6c477cd8 - > tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying > 28-11-2014 07:37:57.804 UTC Debug pjsip: endpoint Response msg > 408/PRACK/cseq=286923527 (tdta0x7fcf6c473ef0) created > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:110: Find target > Sproutlet for request > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:144: Found next > routable URI: > sip:ppsprout1.ims.prod.lan:5054;transport=TCP;lr;service=scscf;billing-role=charge-orig > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:236: Found services > param - scscf > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:236: Found services > param - scscf > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:236: Found services > param - scscf > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:236: Found services > param - scscf > 28-11-2014 07:37:57.804 UTC Debug scscfsproutlet.cpp:343: S-CSCF > Transaction (0x7fcf6c3ceeb0) created > 28-11-2014 07:37:57.804 UTC Verbose sproutletproxy.cpp:1006: Created > Sproutlet scscf-0x7fcf6c3ceeb0 for Request msg PRACK/cseq=286923527 > (tdta0x7fcf6c3d56d0) > 28-11-2014 07:37:57.804 UTC Debug pjutils.cpp:693: Cloned > tdta0x7fcf6c3d56d0 to tdta0x7fcf6c474f00 > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:1067: Remove top > Route header Route: < > sip:ppsprout1.ims.prod.lan:5054;transport=TCP;lr;service=scscf;billing-role=charge-orig > > > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:1500: Adding message > 0x7fcf6c475510 => txdata 0x7fcf6c474fa8 mapping > 28-11-2014 07:37:57.804 UTC Verbose sproutletproxy.cpp:1380: > scscf-0x7fcf6c3ceeb0 pass in dialog request Request msg > PRACK/cseq=286923527 (tdta0x7fcf6c474f00) to Sproutlet > 28-11-2014 07:37:57.804 UTC Info scscfsproutlet.cpp:440: S-CSCF received > in-dialog request > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:236: Found services > param - scscf > 28-11-2014 07:37:57.804 UTC Info scscfsproutlet.cpp:1445: Charging role is > originating > 28-11-2014 07:37:57.804 UTC Debug acr.cpp:1466: Create RalfACR for node > type S-CSCF with role Originating > 28-11-2014 07:37:57.804 UTC Debug acr.cpp:48: Created ACR (0x7fcf6c47e160) > 28-11-2014 07:37:57.804 UTC Debug acr.cpp:166: Created S-CSCF Ralf ACR > 28-11-2014 07:37:57.804 UTC Debug acr.cpp:205: Set record type for P/S-CSCF > 28-11-2014 07:37:57.804 UTC Debug acr.cpp:226: In-dialog PRACK request => > INTERIM_RECORD > 28-11-2014 07:37:57.804 UTC Debug acr.cpp:1200: Stored 0 subscription > identifiers > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:1166: Sproutlet > send_request 0x7fcf6c475510 > 28-11-2014 07:37:57.804 UTC Verbose sproutletproxy.cpp:1191: > scscf-0x7fcf6c3ceeb0 sending Request msg PRACK/cseq=286923527 > (tdta0x7fcf6c474f00) on fork 0 > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:1515: Processing > actions from sproutlet - 0 responses, 1 requests > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:1550: Processing > request 0x7fcf6c474fa8, fork = 0 > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:1668: > scscf-0x7fcf6c3ceeb0 transmitting request on fork 0 > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:1682: > scscf-0x7fcf6c3ceeb0 store reference to non-ACK request Request msg > PRACK/cseq=286923527 (tdta0x7fcf6c474f00) on fork 0 > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:1507: Removing > message 0x7fcf6c475510 => txdata 0x7fcf6c474fa8 mapping > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:110: Find target > Sproutlet for request > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:144: Found next > routable URI: > sip:ppsprout1.ims.prod.lan:5054;transport=TCP;lr;service=scscf;billing-role=charge-term > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:236: Found services > param - scscf > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:236: Found services > param - scscf > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:236: Found services > param - scscf > 28-11-2014 07:37:57.804 UTC Debug sproutletproxy.cpp:236: Found services > param - scscf > 28-11-2014 07:37:57.804 UTC Debug scscfsproutlet.cpp:343: S-CSCF > Transaction (0x7fcf6c209720) created > 28-11-2014 07:37:57.804 UTC Verbose sproutletproxy.cpp:1006: Created > Sproutlet scscf-0x7fcf6c209720 for Request msg PRACK/cseq=286923527 > (tdta0x7fcf6c474f00) > 28-11-2014 07:37:57.805 UTC Debug pjutils.cpp:693: Cloned > tdta0x7fcf6c474f00 to tdta0x7fcf6c478b30 > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:1067: Remove top > Route header Route: < > sip:ppsprout1.ims.prod.lan:5054;transport=TCP;lr;service=scscf;billing-role=charge-term > > > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:1500: Adding message > 0x7fcf6c479140 => txdata 0x7fcf6c478bd8 mapping > 28-11-2014 07:37:57.805 UTC Verbose sproutletproxy.cpp:1380: > scscf-0x7fcf6c209720 pass in dialog request Request msg > PRACK/cseq=286923527 (tdta0x7fcf6c478b30) to Sproutlet > 28-11-2014 07:37:57.805 UTC Info scscfsproutlet.cpp:440: S-CSCF received > in-dialog request > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:236: Found services > param - scscf > 28-11-2014 07:37:57.805 UTC Info scscfsproutlet.cpp:1450: Charging role is > terminating > 28-11-2014 07:37:57.805 UTC Debug acr.cpp:1466: Create RalfACR for node > type S-CSCF with role Terminating > 28-11-2014 07:37:57.805 UTC Debug acr.cpp:48: Created ACR (0x7fcf6c327b80) > 28-11-2014 07:37:57.805 UTC Debug acr.cpp:166: Created S-CSCF Ralf ACR > 28-11-2014 07:37:57.805 UTC Debug acr.cpp:205: Set record type for P/S-CSCF > 28-11-2014 07:37:57.805 UTC Debug acr.cpp:226: In-dialog PRACK request => > INTERIM_RECORD > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:1166: Sproutlet > send_request 0x7fcf6c479140 > 28-11-2014 07:37:57.805 UTC Verbose sproutletproxy.cpp:1191: > scscf-0x7fcf6c209720 sending Request msg PRACK/cseq=286923527 > (tdta0x7fcf6c478b30) on fork 0 > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:1515: Processing > actions from sproutlet - 0 responses, 1 requests > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:1550: Processing > request 0x7fcf6c478bd8, fork = 0 > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:1668: > scscf-0x7fcf6c209720 transmitting request on fork 0 > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:1682: > scscf-0x7fcf6c209720 store reference to non-ACK request Request msg > PRACK/cseq=286923527 (tdta0x7fcf6c478b30) on fork 0 > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:1507: Removing > message 0x7fcf6c479140 => txdata 0x7fcf6c478bd8 mapping > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:110: Find target > Sproutlet for request > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:144: Found next > routable URI: > sip:87100004@[sbc.private.ip.address]:5060;rinstance=ebdc3f2d5251207f;dtg=TG_PCSCF_INT_IP > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:262: Found user - > 87100004 > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:262: Found user - > 87100004 > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:262: Found user - > 87100004 > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:262: Found user - > 87100004 > 28-11-2014 07:37:57.805 UTC Debug sproutletproxy.cpp:783: No local > sproutlet matches request > 28-11-2014 07:37:57.805 UTC Debug pjsip: tsx0x7fcf6c47a Transaction > created for Request msg PRACK/cseq=286923527 (tdta0x7fcf6c478b30) > 28-11-2014 07:37:57.805 UTC Debug basicproxy.cpp:1586: Added trail > identifier 114925 to UAC transaction > 28-11-2014 07:37:57.805 UTC Debug pjutils.cpp:505: Next hop node is > encoded in Request-URI > 28-11-2014 07:37:57.805 UTC Debug sipresolver.cpp:85: SIPResolver::resolve > for name [sbc.private.ip.address], port 5060, transport -1, family 2 > 28-11-2014 07:37:57.805 UTC Debug baseresolver.cpp:511: Attempt to parse > [sbc.private.ip.address] as IP address > 28-11-2014 07:37:57.805 UTC Debug sipresolver.cpp:102: Target is an IP > address - default port/transport if required > 28-11-2014 07:37:57.805 UTC Info pjutils.cpp:940: Resolved destination URI > sip:87100004@[sbc.private.ip.address]:5060;rinstance=ebdc3f2d5251207f;dtg=TG_PCSCF_INT_IP > to 1 servers > 28-11-2014 07:37:57.805 UTC Debug basicproxy.cpp:1613: Sending request for > sip:87100004@[sbc.private.ip.address]:5060;rinstance=ebdc3f2d5251207f;dtg=TG_PCSCF_INT_IP > 28-11-2014 07:37:57.805 UTC Debug pjsip: tsx0x7fcf6c47a Sending Request > msg PRACK/cseq=286923527 (tdta0x7fcf6c478b30) in state Null > 28-11-2014 07:37:57.805 UTC Debug pjsip: endpoint Request msg > PRACK/cseq=286923527 (tdta0x7fcf6c478b30): skipping target resolution > because address is already set > 28-11-2014 07:37:57.805 UTC Verbose stack.cpp:255: TX 562 bytes Request > msg PRACK/cseq=286923527 (tdta0x7fcf6c478b30) to UDP > [sbc.private.ip.address]:5060: > --start msg-- > > PRACK > sip:87100004@[sbc.private.ip.address]:5060;rinstance=ebdc3f2d5251207f;dtg=TG_PCSCF_INT_IP > SIP/2.0 > Via: SIP/2.0/UDP > [sprout.network.ip.address]:5052;rport;branch=z9hG4bKPjLuLZfbrxf04GCCv67sHr-sD1433-p4XE > Via: SIP/2.0/UDP > [sbc.private.ip.address]:5060;received=[sbc.private.ip.address];branch=z9hG4bK0cB126c28029d093c55 > From: <sip:[email protected];pstn-params=9084818088;cpc=ordinary > >;tag=gK0c159f6a > To: <sip:[email protected]>;tag=gK049472a3 > Call-ID: 786540_132020356@[sbc.private.ip.address] > CSeq: 286923527 PRACK > Max-Forwards: 68 > RAck: 2133018667 286923526 INVITE > Session-Expires: 600 > Content-Length: 0 > > > --end msg-- > 28-11-2014 07:37:57.805 UTC Debug pjsip: tsx0x7fcf6c47a State changed from > Null to Calling, event=TX_MSG > 28-11-2014 07:37:57.805 UTC Debug basicproxy.cpp:214: tsx0x7fcf6c47ab98 - > tu_on_tsx_state UAC, TSX_STATE TX_MSG state=Calling > 28-11-2014 07:37:57.805 UTC Debug basicproxy.cpp:1769: tsx0x7fcf6c47ab98 - > uac_tsx = 0x7fcf6c3d4710, uas_tsx = 0x7fcf6c3cd410 > 28-11-2014 07:37:57.805 UTC Debug basicproxy.cpp:1777: TX_MSG event on > current UAC transaction > 28-11-2014 07:37:57.805 UTC Debug stack.cpp:204: Worker thread completed > processing message 0x7fcf640ceb38 > 28-11-2014 07:37:57.805 UTC Debug stack.cpp:210: Request latency = 1340us > 28-11-2014 07:37:57.810 UTC Debug pjsip: sip_endpoint.c Processing > incoming message: Response msg 405/PRACK/cseq=286923527 (rdata0x22f8c48) > 28-11-2014 07:37:57.810 UTC Verbose stack.cpp:239: RX 479 bytes Response > msg 405/PRACK/cseq=286923527 (rdata0x22f8c48) from UDP > [sbc.private.ip.address]:5060: > --start msg-- > > SIP/2.0 405 Method Not Allowed > Via: SIP/2.0/UDP > [sprout.network.ip.address]:5052;branch=z9hG4bKPjLuLZfbrxf04GCCv67sHr-sD1433-p4XE;rport=5052 > Via: SIP/2.0/UDP > [sbc.private.ip.address]:5060;received=[sbc.private.ip.address];branch=z9hG4bK0cB126c28029d093c55 > From: <sip:[email protected];pstn-params=9084818088;cpc=ordinary > >;tag=gK0c159f6a > To: <sip:[email protected]>;tag=gK049472a3 > Call-ID: 786540_132020356@[sbc.private.ip.address] > CSeq: 286923527 PRACK > Allow: INVITE,ACK,CANCEL,BYE,REGISTER,OPTIONS > Content-Length: 0 > > > > 2014-11-27 19:52 GMT+01:00 Eleanor Merry <[email protected]>: > > Hi Abaco, > > I agree with your reading of the scenario. Sprout is just proxying the > PRACK, and so should not add any Route headers. If you send me the debug > logs from Sprout for the request, then I can take a closer look to see if > there's anything else though. You can turn on debug logging by > creating/editing the file /etc/clearwater/user_settings, adding log_level=5 > and then restarting Sprout (service sprout stop - it's automatically > restarted by monit). The Sprout logs are output in /var/log/sprout/*. > > Ellie > > > -----Original Message----- > From: [email protected] [mailto: > [email protected]] On Behalf Of Ruggero > Schiavi > Sent: 26 November 2014 15:48 > To: [email protected] > Subject: [Clearwater] PRACK PROBLEM > > I am sorry to bother another time but I am still locked by a prack problem > raised with our SBC introduction. > > Both the calling part and the callee part are attached to the same SBC. > The SBC generate the Prack from one side and discarding on the other side. > > Raised the problem they answered: > > > > It seems this might be the issue. Per RFC3261, "12.1.2 UAC Behavior", a > snipped text: > > > > "The route set MUST be set to the list of URIs in the Record-Route > > header field from the response, taken in reverse order and preserving > > all URI parameters." > > > > Could you check why S/C-CSCF is not adding Route headers on PRACK? > > > > I answered that for me they were wrong in supposing that Sprout should add > these route headers. Actually in my opinion the SBC is correctly adding > these two headers (and I verified this in their PRACK) and Sprout is > performing normal SIP routing mechanism reading the route headers (both > sprout orig-term) removing them and finally sending (reading the SIP-URI) > to the SBC the Prack for the final destination delivering. > > So in my opinion it is not a Clearwater problem. > > They answered again that it is a S-CSCF problem that should add these two > headers. > > Could you give me any hint to clarify this? Am I wrong and therefore it's > a bug in Sprout or eventually my reasoning sounds correct? Sprout should > add Record-Route header? > > I understand this may not be a direct problem of Clearwater but if they > are right there is something wrong in Sprout (even if I repeat for me > Sprout does everything correctly), I look forward for a reply, > > Thanks a lot, > > Abaco > > _______________________________________________ > Clearwater mailing list > [email protected] > http://lists.projectclearwater.org/listinfo/clearwater > > > _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
