Hi Alan, Thanks for highlighting this! I've raised an issue to track fixing this up (please see https://github.com/Metaswitch/sprout/issues/794). We'll keep this issue updated as we investigate and fix the problem.
Ellie -----Original Message----- From: [email protected] [mailto:[email protected]] On Behalf Of Kwon, Alan Sent: 01 October 2014 21:23 To: [email protected] Subject: [Clearwater] Via header in Response Hi, During my testing of DNS Round-robin from AS to Sprout, I sent in a bogus test message, expecting to get an error. I got the error back alright, but seems like Sprout: 1. Incorrectly adding a Via-header to a response 2. Via header is mal-formed (probably not an issue given that issue 1 is corrected) Below is the (sanitized) log from Sprout node. --start msg-- MESSAGE sip:[email protected] SIP/2.0 Via: SIP/2.0/UDP xx.xx.xx.232:5510;branch=z9hG4bK5d9ba17e-3c34-4369-8f34-c6c13902d671 Via: SIP/2.0/UDP xx.xx.xx.232:6060;branch=z9hG4bKaaa72e2d-5a75-4b7d-8339-89d078ae8216 Call-ID: d6f30e7b00f64a15b15d76b1de066be9 CSeq: 1 MESSAGE From: Alice <sip:[email protected]>;tag=tag-1-0000 To: Bob <sip:[email protected]> P-Asserted-Identity: <sip:[email protected]> User-Agent: IM-serv/OMA1.0 Interop-RMS/2.0 Accept-Contact: *;+g.oma.sip-im Content-Type: message/cpim Contribution-ID: fd37605c-b9c7-4f5e-ab8e-6e99e381d2e5 Conversation-ID: eadb4564-52ae-445b-8f8e-639d1cde3c0a Route: <sip:sprout.cwims.xxx.com:5054;lr> Content-Length: 299 Max-Forwards: 68 From: sip:[email protected] To: sip:[email protected] DateTime: 2014-10-01T20:06:21Z NS: imdn <urn:ietf:params:imdn> imdn.Message-ID: imdn123 imdn.Disposition-Notification: positive-delivery, display Content-Type: text/plain; charset=utf-8 Content-Length: 12 Test case 1 --end msg-- 01-10-2014 20:06:05.374 UTC Debug stack.cpp:457: Queuing cloned received message 0x7ff8d4608ba8 for worker threads 01-10-2014 20:06:05.374 UTC Debug stack.cpp:196: Worker thread dequeue message 0x7ff8d4608ba8 01-10-2014 20:06:05.374 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg MESSAGE/cseq=1 (rdata0x7ff8d4608ba8) 01-10-2014 20:06:05.374 UTC Debug basicproxy.cpp:89: Process MESSAGE request 01-10-2014 20:06:05.374 UTC Verbose sproutletproxy.cpp:430: Sproutlet Proxy transaction (0x24724b0) created 01-10-2014 20:06:05.374 UTC Debug basicproxy.cpp:1232: Report SAS start marker - trail (1bb4c) 01-10-2014 20:06:05.374 UTC Debug pjutils.cpp:1567: Logging SAS Call-ID marker, Call-ID d6f30e7b00f64a15b15d76b1de066be9 01-10-2014 20:06:05.374 UTC Debug pjutils.cpp:654: Cloned Request msg MESSAGE/cseq=1 (rdata0x7ff8d4608ba8) to tdta0x24a6640 01-10-2014 20:06:05.375 UTC Debug pjsip: tsx0x25cf2c8 Transaction created for Request msg MESSAGE/cseq=1 (rdata0x7ff8d4608ba8) 01-10-2014 20:06:05.375 UTC Debug pjsip: tsx0x25cf2c8 Incoming Request msg MESSAGE/cseq=1 (rdata0x7ff8d4608ba8) in state Null 01-10-2014 20:06:05.375 UTC Debug pjsip: tsx0x25cf2c8 State changed from Null to Trying, event=RX_MSG 01-10-2014 20:06:05.375 UTC Debug basicproxy.cpp:214: tsx0x25cf2c8 - tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying 01-10-2014 20:06:05.375 UTC Debug pjsip: endpoint Response msg 408/MESSAGE/cseq=1 (tdta0x25cfa30) created 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:109: Find target Sproutlet for request 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:124: Found top Route header: Route: <sip:sprout.cwims.xxx.com:5054;lr> 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:151: No Sproutlet found using service name or host 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:156: Find default service for port 5054 01-10-2014 20:06:05.375 UTC Debug scscfsproutlet.cpp:306: S-CSCF Transaction (0x246ffd0) created 01-10-2014 20:06:05.375 UTC Verbose sproutletproxy.cpp:954: Created Sproutlet scscf-0x246ffd0 for Request msg MESSAGE/cseq=1 (tdta0x24a6640) 01-10-2014 20:06:05.375 UTC Debug pjutils.cpp:671: Cloned tdta0x24a6640 to tdta0x25d0a40 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1015: Remove top Route header Route: <sip:sprout.cwims.xxx.com:5054;lr> 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1433: Adding message 0x25d1050 => txdata 0x25d0ae8 mapping 01-10-2014 20:06:05.375 UTC Verbose sproutletproxy.cpp:1313: scscf-0x246ffd0 pass initial request Request msg MESSAGE/cseq=1 (tdta0x25d0a40) to Sproutlet 01-10-2014 20:06:05.375 UTC Info scscfsproutlet.cpp:336: S-CSCF received initial request 01-10-2014 20:06:05.375 UTC Debug scscfsproutlet.cpp:546: Route header references this system 01-10-2014 20:06:05.375 UTC Debug scscfsproutlet.cpp:581: Got our Route header, session case term, OD=None 01-10-2014 20:06:05.375 UTC Debug scscfsproutlet.cpp:760: URI is not locally hosted 01-10-2014 20:06:05.375 UTC Debug acr.cpp:48: Created ACR (0x25cde60) 01-10-2014 20:06:05.375 UTC Info scscfsproutlet.cpp:388: Route request to BGCF without applying services 01-10-2014 20:06:05.375 UTC Info scscfsproutlet.cpp:996: Routing to BGCF sip:bgcf.sprout.cwims.xxx.com:5054;transport=TCP 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1114: Sproutlet send_request 0x25d1050 01-10-2014 20:06:05.375 UTC Verbose sproutletproxy.cpp:1139: scscf-0x246ffd0 sending Request msg MESSAGE/cseq=1 (tdta0x25d0a40) on for k 0 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1448: Processing actions from sproutlet - 0 responses, 1 requests 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1485: Processing request 0x25d0ae8, fork = 0 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1599: scscf-0x246ffd0 transmitting request on fork 0 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1613: scscf-0x246ffd0 store reference to non-ACK request Request msg MESSAGE/cseq=1 (tdta0x25d0a40) on fork 0 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1440: Removing message 0x25d1050 => txdata 0x25d0ae8 mapping 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:109: Find target Sproutlet for request 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:124: Found top Route header: Route: <sip:bgcf.sprout.cwims.xxx.com:5054;transport=TCP;lr> 01-10-2014 20:06:05.375 UTC Verbose sproutletproxy.cpp:954: Created Sproutlet bgcf-0x24700f0 for Request msg MESSAGE/cseq=1 (tdta0x25d0a40) 01-10-2014 20:06:05.375 UTC Debug pjutils.cpp:671: Cloned tdta0x25d0a40 to tdta0x25dd9d0 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1015: Remove top Route header Route: <sip:bgcf.sprout.cwims.xxx.com:5054;transport=TCP;lr> 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1433: Adding message 0x25ddfe0 => txdata 0x25dda78 mapping 01-10-2014 20:06:05.375 UTC Verbose sproutletproxy.cpp:1313: bgcf-0x24700f0 pass initial request Request msg MESSAGE/cseq=1 (tdta0x25dd9d0) to Sproutlet 01-10-2014 20:06:05.375 UTC Debug acr.cpp:48: Created ACR (0x24a5590) 01-10-2014 20:06:05.375 UTC Debug bgcfservice.cpp:137: Getting route for URI domain ims.xxx.com via BGCF lookup 01-10-2014 20:06:05.375 UTC Debug bgcfsproutlet.cpp:161: No route configured for ims.xxx.com 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1114: Sproutlet send_request 0x25ddfe0 01-10-2014 20:06:05.375 UTC Verbose sproutletproxy.cpp:1139: bgcf-0x24700f0 sending Request msg MESSAGE/cseq=1 (tdta0x25dd9d0) on fork 0 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1448: Processing actions from sproutlet - 0 responses, 1 requests 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1485: Processing request 0x25dda78, fork = 0 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1599: bgcf-0x24700f0 transmitting request on fork 0 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1613: bgcf-0x24700f0 store reference to non-ACK request Request msg MESSAGE/cseq=1 (tdta0x25dd9d0) on fork 0 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1440: Removing message 0x25ddfe0 => txdata 0x25dda78 mapping 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:109: Find target Sproutlet for request 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:740: No local sproutlet matches request 01-10-2014 20:06:05.375 UTC Debug pjsip: tsx0x25d1af8 Transaction created for Request msg MESSAGE/cseq=1 (tdta0x25dd9d0) 01-10-2014 20:06:05.375 UTC Debug basicproxy.cpp:1563: Added trail identifier 113484 to UAC transaction 01-10-2014 20:06:05.375 UTC Debug pjutils.cpp:483: Next hop node is encoded in Request-URI 01-10-2014 20:06:05.375 UTC Debug sipresolver.cpp:85: SIPResolver::resolve for name ims.xxx.com, port 0, transport -1, family 2 01-10-2014 20:06:05.375 UTC Debug baseresolver.cpp:511: Attempt to parse ims.xxx.com as IP address 01-10-2014 20:06:05.375 UTC Debug sipresolver.cpp:144: Do NAPTR look-up for ims.xxx.com 01-10-2014 20:06:05.375 UTC Debug ttlcache.h:171: Found the entry in the cache 01-10-2014 20:06:05.375 UTC Debug sipresolver.cpp:158: NAPTR resolved to transport 17 01-10-2014 20:06:05.375 UTC Debug sipresolver.cpp:280: Do SRV lookup for _sip._udp.ims.xxx.com 01-10-2014 20:06:05.375 UTC Debug ttlcache.h:171: Found the entry in the cache 01-10-2014 20:06:05.375 UTC Info pjutils.cpp:918: Resolved destination URI sip:[email protected] to 0 servers 01-10-2014 20:06:05.375 UTC Debug basicproxy.cpp:1590: Sending request for sip:[email protected] 01-10-2014 20:06:05.375 UTC Debug basicproxy.cpp:1639: Failed to send request (70006 Not found (PJ_ENOTFOUND)) 01-10-2014 20:06:05.375 UTC Debug basicproxy.cpp:1363: Dissociate UAC transaction 0x25cbc90 for target 0 01-10-2014 20:06:05.375 UTC Verbose sproutletproxy.cpp:1380: bgcf-0x24700f0 received error TRANSPORT_ERROR on fork 0, state = Calling 01-10-2014 20:06:05.375 UTC Info pjutils.cpp:1536: Cloning header! 39709984 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1433: Adding message 0x25dffa0 => txdata 0x25dfa38 mapping 01-10-2014 20:06:05.375 UTC Verbose sproutletproxy.cpp:1166: bgcf-0x24700f0 sending Response msg 503/MESSAGE/cseq=1 (tdta0x25df990) 01-10-2014 20:06:05.375 UTC Debug sproutletproxy.cpp:1448: Processing actions from sproutlet - 1 responses, 0 requests 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1521: Aggregating response with status code 503 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1571: 3xx/4xx/5xx/6xx response 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1575: Best 3xx/4xx/5xx/6xx response so far 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1470: All UAC responded 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1440: Removing message 0x25dffa0 => txdata 0x25dfa38 mapping 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1433: Adding message 0x25dffa0 => txdata 0x25dfa38 mapping 01-10-2014 20:06:05.376 UTC Verbose sproutletproxy.cpp:1347: scscf-0x246ffd0 received final response Response msg 503/MESSAGE/cseq=1 (tdta0x25df990) on fork 0, state = Terminated 01-10-2014 20:06:05.376 UTC Info scscfsproutlet.cpp:426: S-CSCF received response 01-10-2014 20:06:05.376 UTC Verbose sproutletproxy.cpp:1166: scscf-0x246ffd0 sending Response msg 503/MESSAGE/cseq=1 (tdta0x25df990) 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1448: Processing actions from sproutlet - 1 responses, 0 requests 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1521: Aggregating response with status code 503 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1571: 3xx/4xx/5xx/6xx response 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1575: Best 3xx/4xx/5xx/6xx response so far 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1470: All UAC responded 01-10-2014 20:06:05.376 UTC Debug sproutletproxy.cpp:1440: Removing message 0x25dffa0 => txdata 0x25dfa38 mapping 01-10-2014 20:06:05.376 UTC Debug pjsip: tsx0x25cf2c8 Sending Response msg 503/MESSAGE/cseq=1 (tdta0x25df990) in state Trying 01-10-2014 20:06:05.376 UTC Debug pjsip: sip_resolve.c Target 'xx.xx.xx.232:5510' type=UDP resolved to 'xx.xx.xx.232:5510' type=UDP (UDP transport) 01-10-2014 20:06:05.376 UTC Verbose stack.cpp:249: TX 661 bytes Response msg 503/MESSAGE/cseq=1 (tdta0x25df990) to UDP xx.xx.xx.232:5510: --start msg-- SIP/2.0 503 Service Unavailable Via: SIP/2.0/ ;branch=z9hG4bKPj1wlTCuIYAGNTBj4BTN3xDIvJavXvsL92 Via: SIP/2.0/UDP xx.xx.xx.232:5510;received=xx.xx.xx.232;branch=z9hG4bK5d9ba17e-3c34-4369-8f34-c6c13902d671 Via: SIP/2.0/UDP xx.xx.xx.232:6060;branch=z9hG4bKaaa72e2d-5a75-4b7d-8339-89d078ae8216 Call-ID: d6f30e7b00f64a15b15d76b1de066be9 From: "Alice" <sip:[email protected]>;tag=tag-1-0000 To: "Bob" <sip:[email protected]>;tag=z9hG4bKPj1wlTCuIYAGNTBj4BTN3xDIvJavXvsL92 CSeq: 1 MESSAGE Content-Length: 0 --end msg-- Thanks, Alan _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
