Hi, I’ve updated to “Katamari Damacy” release and session establishment is failing due to To-header tag mismatch. My AS is sending a SIP INVITE and Sprout is adding a To-tag in the 100 Trying response :
To: <sip:[email protected];user=phone>;tag=z9hG4bK6a1d67ce-980c-4657-9e40-e81cf2e8f11e Then it forwards the SIP INVITE to Bono. When 180 Ringing / 200 OK comes back from the client, it carries a different To-tag: To: <sip:[email protected];user=phone>;tag=zN9xOqBRwrxf5JySLbAvvEqlHlbKa4z. Since the tags mismatch, it can’t be processed. Sprout shouldn’t set the tag for the 100 Trying it sends out. Below is the relevant sections from the Sprout node’s log file. ----------------------------------------------------------------------------------------------------- --start msg-- INVITE sip:[email protected];user=phone SIP/2.0 Via: SIP/2.0/UDP xx.xx.xx.71:5510;branch=z9hG4bK6a1d67ce-980c-4657-9e40-e81cf2e8f11e From: <sip:[email protected]>;tag=ffe8b498-fc4f-46f9-bf84-aa4a8689d6d2 To: <sip:[email protected];user=phone> Call-ID: d3c9352b-5501-48b7-8359-526d00799e34 CSeq: 1 INVITE … --end msg-- 29-07-2014 20:10:33.935 UTC Debug statistic.cpp:103: Send new value for statistic incoming_requests, size 1 29-07-2014 20:10:33.935 UTC Debug stack.cpp:425: Queuing cloned received message 0x7f56304a7be8 for worker threads 29-07-2014 20:10:33.935 UTC Debug zmq_lvc.cpp:167: Update to incoming_requests statistic 29-07-2014 20:10:33.935 UTC Debug zmq_lvc.cpp:250: Clearing message cache for 0x7f568402a170 29-07-2014 20:10:33.935 UTC Debug stack.cpp:195: Worker thread dequeue message 0x7f56304a7be8 29-07-2014 20:10:33.935 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=1 (rdata0x7f56304a7be8) 29-07-2014 20:10:33.935 UTC Debug stateful_proxy.cpp:259: Proxy RX request 29-07-2014 20:10:33.935 UTC Debug stateful_proxy.cpp:452: Initial (not in-dialog) request for routing proxy 29-07-2014 20:10:33.935 UTC Debug stateful_proxy.cpp:496: Got our Route header, session case orig, OD=None 29-07-2014 20:10:33.935 UTC Debug acr.cpp:48: Created ACR (0x7f56300da700) 29-07-2014 20:10:33.935 UTC Debug pjutils.cpp:481: Found Route header, URI = sip:sprout.example.com:5054;transport=UDP;lr;orig 29-07-2014 20:10:33.935 UTC Debug pjutils.cpp:484: Route header is local 29-07-2014 20:10:33.935 UTC Debug stateful_proxy.cpp:1622: Top Route header is local - erasing 29-07-2014 20:10:33.935 UTC Debug stateful_proxy.cpp:595: Trust mode TRUSTED(,,), serving state orig (new) 29-07-2014 20:10:33.935 UTC Debug pjsip: tsx0x7f56300d7 Transaction created for Request msg INVITE/cseq=1 (rdata0x7f56304a7be8) 29-07-2014 20:10:33.935 UTC Debug stateful_proxy.cpp:2107: UASTransaction constructor (0x7f56304a8fe0) 29-07-2014 20:10:33.935 UTC Debug stateful_proxy.cpp:2108: ACR (0x7f56300da700) 29-07-2014 20:10:33.935 UTC Debug pjsip: tsx0x7f56300d7 Incoming Request msg INVITE/cseq=1 (rdata0x7f56304a7be8) in state Null 29-07-2014 20:10:33.935 UTC Debug pjsip: tsx0x7f56300d7 State changed from Null to Trying, event=RX_MSG 29-07-2014 20:10:33.935 UTC Debug stateful_proxy.cpp:367: tsx0x7f56300d7e08 - tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying 29-07-2014 20:10:33.935 UTC Debug pjsip: endpoint Response msg 408/INVITE/cseq=1 (tdta0x7f5630494090) created 29-07-2014 20:10:33.935 UTC Debug stateful_proxy.cpp:3542: Report SAS start marker - trail (d2) 29-07-2014 20:10:33.935 UTC Debug pjutils.cpp:1364: Logging SAS Call-ID marker, Call-ID d3c9352b-5501-48b7-8359-526d00799e34 29-07-2014 20:10:33.935 UTC Debug pjsip: tsx0x7f56300d7 Sending Response msg 100/INVITE/cseq=1 (tdta0x7f56304952b0) in state Trying 29-07-2014 20:10:33.935 UTC Debug pjsip: sip_resolve.c Target 'xx.xx.xx.71:5510' type=UDP resolved to 'xx.xx.xx.71:5510' type=UDP (UDP transport) 29-07-2014 20:10:33.935 UTC Verbose stack.cpp:248: TX 386 bytes Response msg 100/INVITE/cseq=1 (tdta0x7f56304952b0) to UDP xx.xx.xx.71:5510: --start msg-- SIP/2.0 100 Trying Via: SIP/2.0/UDP xx.xx.xx.71:5510;received=xx.xx.xx.71;branch=z9hG4bK6a1d67ce-980c-4657-9e40-e81cf2e8f11e Call-ID: d3c9352b-5501-48b7-8359-526d00799e34 From: <sip:[email protected]>;tag=ffe8b498-fc4f-46f9-bf84-aa4a8689d6d2 To: <sip:[email protected];user=phone>;tag=z9hG4bK6a1d67ce-980c-4657-9e40-e81cf2e8f11e CSeq: 1 INVITE Content-Length: 0 --end msg-- … --start msg-- SIP/2.0 100 Trying Via: SIP/2.0/TCP xx.xx.xx.97:34066;rport=34066;received=xx.xx.xx.97;branch=z9hG4bKPj54i0w6TUO1rmh3Snl-3iGEpa77xZUGTU Via: SIP/2.0/UDP xx.xx.xx.71:5510;received=xx.xx.xx.71;branch=z9hG4bK6a1d67ce-980c-4657-9e40-e81cf2e8f11e Record-Route: <sip:[email protected]:5060;transport=TCP;lr> Record-Route: <sip:xx.xx.xx.96:5058;transport=TCP;lr> Record-Route: <sip:sprout.example.com:5054;transport=TCP;lr;charge-orig;charge-term> Call-ID: d3c9352b-5501-48b7-8359-526d00799e34 From: <sip:[email protected]>;tag=ffe8b498-fc4f-46f9-bf84-aa4a8689d6d2 To: <sip:[email protected];user=phone> CSeq: 1 INVITE Content-Length: 0 --end msg-- 29-07-2014 20:10:34.178 UTC Debug stack.cpp:425: Queuing cloned received message 0x7f56304a7be8 for worker threads 29-07-2014 20:10:34.178 UTC Debug stack.cpp:195: Worker thread dequeue message 0x7f56304a7be8 29-07-2014 20:10:34.178 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 100/INVITE/cseq=1 (rdata0x7f56304a7be8) 29-07-2014 20:10:34.178 UTC Debug pjsip: tsx0x7f5630523 Incoming Response msg 100/INVITE/cseq=1 (rdata0x7f56304a7be8) in state Calling 29-07-2014 20:10:34.178 UTC Debug pjsip: tsx0x7f5630523 State changed from Calling to Proceeding, event=RX_MSG 29-07-2014 20:10:34.178 UTC Debug stateful_proxy.cpp:367: tsx0x7f5630523c48 - tu_on_tsx_state UAC, TSX_STATE RX_MSG state=Proceeding 29-07-2014 20:10:34.178 UTC Debug stateful_proxy.cpp:4270: tsx0x7f5630523c48 - uac_data = 0x7f5630520ab0, uas_data = 0x7f56304a8fe0 29-07-2014 20:10:34.178 UTC Debug stateful_proxy.cpp:4309: tsx0x7f5630523c48 - RX_MSG on active UAC transaction 29-07-2014 20:10:34.178 UTC Debug stateful_proxy.cpp:3097: tsx0x7f5630523c48 - Discard 100/INVITE response 29-07-2014 20:10:34.178 UTC Debug stack.cpp:197: Worker thread completed processing message 0x7f56304a7be8 29-07-2014 20:10:34.178 UTC Debug stack.cpp:203: Request latency = 132us 29-07-2014 20:10:34.184 UTC Debug pjsip: sip_endpoint.c Processing incoming message: Response msg 180/INVITE/cseq=1 (rdata0x7f567410f838) 29-07-2014 20:10:34.184 UTC Verbose stack.cpp:232: RX 926 bytes Response msg 180/INVITE/cseq=1 (rdata0x7f567410f838) from TCP 10.12.92.96:5058: --start msg-- SIP/2.0 180 Ringing Via: SIP/2.0/TCP xx.xx.xx.97:34066;rport=34066;received=xx.xx.xx.97;branch=z9hG4bKPj54i0w6TUO1rmh3Snl-3iGEpa77xZUGTU Via: SIP/2.0/UDP xx.xx.xx.71:5510;received=xx.xx.xx.71;branch=z9hG4bK6a1d67ce-980c-4657-9e40-e81cf2e8f11e Record-Route: <sip:[email protected]:5060;transport=TCP;lr> Record-Route: <sip:xx.xx.xx.96:5058;transport=TCP;lr> Record-Route: <sip:sprout.example.com:5054;transport=TCP;lr;charge-orig;charge-term> Call-ID: d3c9352b-5501-48b7-8359-526d00799e34 From: <sip:[email protected]>;tag=ffe8b498-fc4f-46f9-bf84-aa4a8689d6d2 To: <sip:[email protected];user=phone>;tag=zN9xOqBRwrxf5JySLbAvvEqlHlbKa4z. CSeq: 1 INVITE Contact: <sip:[email protected]:44539;transport=TCP;ob>;+sip.instance="<urn:gsma:imei:35526604-120149-0>" Allow: PRACK, INFO, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Content-Length: 0 --end msg-- 29-07-2014 20:10:34.184 UTC Debug stack.cpp:425: Queuing cloned received message 0x7f5630490218 for worker threads 29-07-2014 20:10:34.184 UTC Debug stack.cpp:195: Worker thread dequeue message 0x7f5630490218 29-07-2014 20:10:34.184 UTC Debug pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 180/INVITE/cseq=1 (rdata0x7f5630490218) 29-07-2014 20:10:34.184 UTC Debug pjsip: tsx0x7f5630523 Incoming Response msg 180/INVITE/cseq=1 (rdata0x7f5630490218) in state Proceeding 29-07-2014 20:10:34.184 UTC Debug pjsip: tsx0x7f5630523 State changed from Proceeding to Proceeding, event=RX_MSG 29-07-2014 20:10:34.184 UTC Debug stateful_proxy.cpp:367: tsx0x7f5630523c48 - tu_on_tsx_state UAC, TSX_STATE RX_MSG state=Proceeding 29-07-2014 20:10:34.184 UTC Debug stateful_proxy.cpp:4270: tsx0x7f5630523c48 - uac_data = 0x7f5630520ab0, uas_data = 0x7f56304a8fe0 29-07-2014 20:10:34.184 UTC Debug stateful_proxy.cpp:4309: tsx0x7f5630523c48 - RX_MSG on active UAC transaction 29-07-2014 20:10:34.185 UTC Debug stateful_proxy.cpp:3245: tsx0x7f5630523c48 - Forward provisional response on UAS transaction 29-07-2014 20:10:34.185 UTC Debug pjsip: tsx0x7f56300d7 Sending Response msg 180/INVITE/cseq=1 (tdta0x7f568404a540) in state Proceeding 29-07-2014 20:10:34.185 UTC Debug pjsip: tdta0x7f563049 Destroying txdata Response msg 100/INVITE/cseq=1 (tdta0x7f56304952b0) 29-07-2014 20:10:34.185 UTC Verbose stack.cpp:248: TX 808 bytes Response msg 180/INVITE/cseq=1 (tdta0x7f568404a540) to UDP xx.xx.xx.71:5510: --start msg-- SIP/2.0 180 Ringing Via: SIP/2.0/UDP xx.xx.xx.71:5510;received=xx.xx.xx.71;branch=z9hG4bK6a1d67ce-980c-4657-9e40-e81cf2e8f11e Record-Route: <sip:[email protected]:5060;transport=TCP;lr> Record-Route: <sip:xx.xx.xx.96:5058;transport=TCP;lr> Record-Route: <sip:sprout.example.com:5054;transport=TCP;lr;charge-orig;charge-term> Call-ID: d3c9352b-5501-48b7-8359-526d00799e34 From: <sip:[email protected]>;tag=ffe8b498-fc4f-46f9-bf84-aa4a8689d6d2 To: <sip:[email protected];user=phone>;tag=zN9xOqBRwrxf5JySLbAvvEqlHlbKa4z. CSeq: 1 INVITE Contact: <sip:[email protected]:44539;transport=TCP;ob>;+sip.instance="<urn:gsma:imei:35526604-120149-0>" Allow: PRACK, INFO, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Content-Length: 0 ----------------------------------------------------------------------------------------------------- Thanks, Alan _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
