[OpenSIPS-Users] YNT: Re: YNT: Re: YNT: Re: RFC3261 transaction matching failed error for the second 401 Unauthorized - Challenging the UE

Kaan Dandin kaandandin at yahoo.com
Wed Oct 15 23:25:34 CEST 2014


Hi Bogdan,

Thanks for your response. I have check the related documentation once more.
But it in fact, I was already using record_route and loose_route.

When I receive initial INVITE I use record_route.

When the following messages has to_tag , I am checking with loose_route and making the routing with t_relay.

This is working properly for the messages before ACK and BYE.

But for ACK and  BYE messages it is not able to find route and  making a DNS lookup  and since
pcscf.open-ims.test is configured as 192.168.2.5 , it is always going to .5 openims node.

The difference between 180 Ringing , 200 OK which is passed properly and ACK and BYE messages seems Via headers. 180 Ringing has all the via headers.

related part of script for record_route()

        else if (is_method("INVITE")) {
                #load_balance("1","pstn");
                xlog("xlog_initialinvite");
                if($si=="192.168.2.11") {

                               ds_select_dst("1","1");
                }
                record_route();
                if(!t_relay()) {
                sl_reply_error();
                xlog("xlog_invitereplyerror");
                }
                exit;
        }



wireshark log

No.     Time        Source                Destination           Protocol Info
   4647 79.393261   192.168.2.11          192.168.2.141         SIP/SDP  Request: INVITE sip:subs000174 at open-ims.test, with session description
   4648 79.395108   192.168.2.141         192.168.2.11          SIP      Status: 100 Giving a try
   4649 79.395467   192.168.2.141         192.168.2.3           SIP/SDP  Request: INVITE sip:subs000174 at open-ims.test, with session description
   4650 79.426101   192.168.2.3           192.168.2.141         SIP      Status: 100 trying -- your call is important to us
   4651 79.464427   192.168.2.3           192.168.2.141         SIP/SDP  Request: INVITE sip:subs000174 at 192.168.2.11:7174, with session description
   4652 79.465264   192.168.2.141         192.168.2.3           SIP      Status: 100 Giving a try
   4654 79.465773   192.168.2.141         192.168.2.11          SIP/SDP  Request: INVITE sip:subs000174 at 192.168.2.11:7174, with session description
   4655 79.465773   192.168.2.11          192.168.2.141         SIP      Status: 180 Ringing
   4656 79.466172   192.168.2.141         192.168.2.3           SIP      Status: 180 Ringing
   4657 79.507893   192.168.2.3           192.168.2.141         SIP      Status: 180 Ringing
   4658 79.508153   192.168.2.141         192.168.2.11          SIP      Status: 180 Ringing
   5053 84.372654   192.168.2.11          192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   5054 84.372931   192.168.2.141         192.168.2.3           SIP/SDP  Status: 200 OK, with session description
   5055 84.396628   192.168.2.3           192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   5056 84.397036   192.168.2.141         192.168.2.11          SIP/SDP  Status: 200 OK, with session description
   5057 84.397552   192.168.2.11          192.168.2.141         SIP      Request: ACK sip:subs000174 at 192.168.2.11:7174;transport=UDP
   5058 84.398921   192.168.2.141         192.168.2.5           SIP      Request: ACK sip:subs000174 at 192.168.2.11:7174;transport=UDP
   5075 84.874990   192.168.2.11          192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   5076 84.875713   192.168.2.141         192.168.2.3           SIP/SDP  Status: 200 OK, with session description
   5077 84.925133   192.168.2.3           192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   5078 84.925434   192.168.2.141         192.168.2.11          SIP/SDP  Status: 200 OK, with session description
   5079 84.925622   192.168.2.11          192.168.2.141         SIP      Request: ACK sip:subs000174 at 192.168.2.11:7174;transport=UDP
   5080 84.926591   192.168.2.141         192.168.2.5           SIP      Request: ACK sip:subs000174 at 192.168.2.11:7174;transport=UDP
   5418 85.876690   192.168.2.11          192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   5419 85.876692   192.168.2.141         192.168.2.3           SIP/SDP  Status: 200 OK, with session description
   5420 85.936150   192.168.2.3           192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   5421 85.936625   192.168.2.141         192.168.2.11          SIP/SDP  Status: 200 OK, with session description
   5422 85.936815   192.168.2.11          192.168.2.141         SIP      Request: ACK sip:subs000174 at 192.168.2.11:7174;transport=UDP
   5423 85.937798   192.168.2.141         192.168.2.5           SIP      Request: ACK sip:subs000174 at 192.168.2.11:7174;transport=UDP
   5440 87.883590   192.168.2.11          192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   5441 87.884024   192.168.2.141         192.168.2.3           SIP/SDP  Status: 200 OK, with session description
   5445 87.960207   192.168.2.3           192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   5447 87.960454   192.168.2.141         192.168.2.11          SIP/SDP  Status: 200 OK, with session description
   5448 87.961156   192.168.2.11          192.168.2.141         SIP      Request: ACK sip:subs000174 at 192.168.2.11:7174;transport=UDP
   5449 87.961157   192.168.2.141         192.168.2.5           SIP      Request: ACK sip:subs000174 at 192.168.2.11:7174;transport=UDP
   5522 91.888474   192.168.2.11          192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   6137 95.893241   192.168.2.11          192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   6228 99.902322   192.168.2.11          192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   6327 103.908286  192.168.2.11          192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   7097 107.919189  192.168.2.11          192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   7241 111.925927  192.168.2.11          192.168.2.141         SIP/SDP  Status: 200 OK, with session description
   8781 133.854566  192.168.2.11          192.168.2.141         SIP      Request: BYE sip:subs000174 at 192.168.2.11:7174;transport=UDP
   8782 133.855367  192.168.2.141         192.168.2.5           SIP      Request: BYE sip:subs000174 at 192.168.2.11:7174;transport=UDP
   8783 133.856357  192.168.2.5           192.168.2.141         SIP      Status: 403 Forbidden - Originating subsequent requests outside dialog not allowed




Opensips related log

ct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: xlog method: [ACK] totag: [3283SIPpTag01173] sipid: [192.168.2.11] messageid:  [883] callid:  [173-3283 at 192.168.2.11] callsequence: [1]
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:uri:has_totag: totag found
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: xlog_has_totag
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:parse_headers: flags=200
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:get_hdr_field: content_length=0
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:get_hdr_field: found end of header
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:rr:find_first_route: No Route headers found
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:rr:loose_route: There is no Route HF
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: xlog_ack_method
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:parse_headers: flags=78
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:tm:t_lookup_request: start searching: hash=58738, isACK=1
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:parse_headers: flags=38
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:parse_to_param: tag=3283SIPpTag00173
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:parse_to: end of header reached, state=29
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:parse_to: display={"subs004916"}, ruri={sip:subs004916 at open-ims.test}
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:tm:t_lookup_request: REF_UNSAFE:[0x7f81f6570408] after is 1
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:tm:t_lookup_request: e2e proxy ACK found
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: xlog_nonlooseroutestatefulack
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:tm:t_newtran: transaction on entrance=(nil)
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:parse_headers: flags=ffffffffffffffff
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:tm:t_newtran: building branch for end2end ACK - flags=1
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:tm:t_relay_to: forwarding ACK
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:mk_proxy: doing DNS lookup...
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:check_ip_address: params 192.168.2.11, 192.168.2.11, 0
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:forward_request: sending:#012ACK sip:subs000129 at 192.168.2.11:7129;transport=UDP SIP/2.0#015#012Record-Route: <sip:192.168.2.141;lr;ftag=3283SIPpTag00173>#015#012Via: SIP/2.0/UDP 192.168.2.141:4060;branch=z9hG4bK275e.11b33e95.2#015#012Via: SIP/2.0/UDP 192.168.2.11:11916;branch=z9hG4bK-3283-173-4#015#012Max-Forwards: 70#015#012Record-Route: <sip:192.168.2.141;lr;ftag=3283SIPpTag00173>#015#012Record-Route: <sip:mt at pcscf.open-ims.test:4060;lr>#015#012Record-Route: <sip:mt at scscf.open-ims.test:6060;lr>#015#012Record-Route: <sip:mo at scscf.open-ims.test:6060;lr>#015#012Record-Route: <sip:mo at pcscf.open-ims.test:4060;lr>#015#012Record-Route: <sip:192.168.2.141;lr;ftag=3283SIPpTag00173>#015#012From: "subs004916" <sip:subs004916 at open-ims.test>;tag=3283SIPpTag00173#015#012To: "subs000129" <sip:subs000129 at open-ims.test>;tag=3283SIPpTag01174;tag=3283SIPpTag01173#015#012Call-ID:
 173-3283 at 192.168.2.11#015#012CSeq: 1 INVITE#015#012Content-Length: 0#015#012#015#012.
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:forward_request: orig. len=701, new_len=828, proto=1
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:tm:t_unref_cell: UNREF_UNSAFE: [0x7f81f6570408] after is 0
Oct 15 13:01:27 ubuntu /usr/local/opensips/sbin/opensips[4329]: DBG:core:destroy_avp_list: destroying list (nil)


Details of 180 Ringing which is passed properly


No.     Time        Source                Destination           Protocol Info
   3263 49.371030   192.168.2.11          192.168.2.141         SIP      Status: 180 Ringing

Frame 3263 (1177 bytes on wire, 1177 bytes captured)
    Arrival Time: Oct 15, 2014 22:54:17.241278000
    [Time delta from previous captured frame: 0.002010000 seconds]
    [Time delta from previous displayed frame: 0.002010000 seconds]
    [Time since reference or first frame: 49.371030000 seconds]
    Frame Number: 3263
    Frame Length: 1177 bytes
    Capture Length: 1177 bytes
    [Frame is marked: False]
    [Protocols in frame: eth:ip:udp:sip]
    [Coloring Rule Name: UDP]
    [Coloring Rule String: udp]
Ethernet II, Src: Vmware_d2:6a:2a (00:0c:29:d2:6a:2a), Dst: Vmware_22:e0:4c (00:0c:29:22:e0:4c)
    Destination: Vmware_22:e0:4c (00:0c:29:22:e0:4c)
        Address: Vmware_22:e0:4c (00:0c:29:22:e0:4c)
        .... ...0 .... .... .... .... = IG bit: Individual address (unicast)
        .... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
    Source: Vmware_d2:6a:2a (00:0c:29:d2:6a:2a)
        Address: Vmware_d2:6a:2a (00:0c:29:d2:6a:2a)
        .... ...0 .... .... .... .... = IG bit: Individual address (unicast)
        .... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
    Type: IP (0x0800)
Internet Protocol, Src: 192.168.2.11 (192.168.2.11), Dst: 192.168.2.141 (192.168.2.141)
    Version: 4
    Header length: 20 bytes
    Differentiated Services Field: 0x00 (DSCP 0x00: Default; ECN: 0x00)
        0000 00.. = Differentiated Services Codepoint: Default (0x00)
        .... ..0. = ECN-Capable Transport (ECT): 0
        .... ...0 = ECN-CE: 0
    Total Length: 1163
    Identification: 0x504b (20555)
    Flags: 0x04 (Don't Fragment)
        0... = Reserved bit: Not set
        .1.. = Don't fragment: Set
        ..0. = More fragments: Not set
    Fragment offset: 0
    Time to live: 64
    Protocol: UDP (0x11)
    Header checksum: 0x602e [correct]
        [Good: True]
        [Bad : False]
    Source: 192.168.2.11 (192.168.2.11)
    Destination: 192.168.2.141 (192.168.2.141)
User Datagram Protocol, Src Port: 11630 (11630), Dst Port: dsmeter_iatc (4060)
    Source port: 11630 (11630)
    Destination port: dsmeter_iatc (4060)
    Length: 1143
    Checksum: 0xb322 [correct]
        [Good Checksum: True]
        [Bad Checksum: False]
Session Initiation Protocol
    Status-Line: SIP/2.0 180 Ringing
        Status-Code: 180
        [Resent Packet: False]
    Message Header
        Via: SIP/2.0/UDP 192.168.2.141:4060;branch=z9hG4bKd619.6d0c1795.0
            Transport: UDP
            Sent-by Address: 192.168.2.141
            Sent-by port: 4060
            Branch: z9hG4bKd619.6d0c1795.0
        Via: SIP/2.0/UDP 192.168.2.3:4060;branch=z9hG4bKd619.d62fc68.0
            Transport: UDP
            Sent-by Address: 192.168.2.3
            Sent-by port: 4060
            Branch: z9hG4bKd619.d62fc68.0
        Via: SIP/2.0/UDP 192.168.2.3:6060;received=192.168.2.3;rport=6060;branch=z9hG4bKd619.b137ec01.0
            Transport: UDP
            Sent-by Address: 192.168.2.3
            Sent-by port: 6060
            Received: 192.168.2.3
            RPort: 6060
            Branch: z9hG4bKd619.b137ec01.0
        Via: SIP/2.0/UDP 192.168.2.3:6060;branch=z9hG4bKd619.a137ec01.0
            Transport: UDP
            Sent-by Address: 192.168.2.3
            Sent-by port: 6060
            Branch: z9hG4bKd619.a137ec01.0
        Via: SIP/2.0/UDP 192.168.2.3:4060;branch=z9hG4bKd619.c62fc68.0
            Transport: UDP
            Sent-by Address: 192.168.2.3
            Sent-by port: 4060
            Branch: z9hG4bKd619.c62fc68.0
        Via: SIP/2.0/UDP 192.168.2.141:4060;received=192.168.2.141;rport=4060;branch=z9hG4bKd619.5d0c1795.0
            Transport: UDP
            Sent-by Address: 192.168.2.141
            Sent-by port: 4060
            Received: 192.168.2.141
            RPort: 4060
            Branch: z9hG4bKd619.5d0c1795.0
        Via: SIP/2.0/UDP 192.168.2.11:10800;branch=z9hG4bK-3501-57-4
            Transport: UDP
            Sent-by Address: 192.168.2.11
            Sent-by port: 10800
            Branch: z9hG4bK-3501-57-4
        Record-Route: <sip:192.168.2.141;lr;ftag=3501SIPpTag0057>
        Record-Route: <sip:mt at pcscf.open-ims.test:4060;lr>
        Record-Route: <sip:mt at scscf.open-ims.test:6060;lr>
        Record-Route: <sip:mo at scscf.open-ims.test:6060;lr>
        Record-Route: <sip:mo at pcscf.open-ims.test:4060;lr>
        Record-Route: <sip:192.168.2.141;lr;ftag=3501SIPpTag0057>
        From: "subs003800" <sip:subs003800 at open-ims.test>;tag=3501SIPpTag0057
            SIP Display info: "subs003800" 
            SIP from address: sip:subs003800 at open-ims.test
            SIP tag: 3501SIPpTag0057
        To: "subs004630" <sip:subs004630 at open-ims.test>;tag=3501SIPpTag0158
            SIP Display info: "subs004630" 
            SIP to address: sip:subs004630 at open-ims.test
            SIP tag: 3501SIPpTag0158
        Call-ID: 57-3501 at 192.168.2.11
        CSeq: 1 INVITE
            Sequence Number: 1
            Method: INVITE
        Contact: <sip:subs004630 at 192.168.2.11:11630;transport=UDP>
            Contact Binding: <sip:subs004630 at 192.168.2.11:11630;transport=UDP>
                URI: <sip:subs004630 at 192.168.2.11:11630;transport=UDP>
                    SIP contact address: sip:subs004630 at 192.168.2.11:11630
        Content-Length:


sample ack message

No.     Time        Source                Destination           Protocol Info
   3271 49.468199   192.168.2.11          192.168.2.141         SIP      Request: ACK sip:subs000663 at 192.168.2.11:7663;transport=UDP

Frame 3271 (636 bytes on wire, 636 bytes captured)
    Arrival Time: Oct 15, 2014 22:54:17.338447000
    [Time delta from previous captured frame: 0.000420000 seconds]
    [Time delta from previous displayed frame: 0.000420000 seconds]
    [Time since reference or first frame: 49.468199000 seconds]
    Frame Number: 3271
    Frame Length: 636 bytes
    Capture Length: 636 bytes
    [Frame is marked: False]
    [Protocols in frame: eth:ip:udp:sip]
    [Coloring Rule Name: UDP]
    [Coloring Rule String: udp]
Ethernet II, Src: Vmware_d2:6a:2a (00:0c:29:d2:6a:2a), Dst: Vmware_22:e0:4c (00:0c:29:22:e0:4c)
    Destination: Vmware_22:e0:4c (00:0c:29:22:e0:4c)
        Address: Vmware_22:e0:4c (00:0c:29:22:e0:4c)
        .... ...0 .... .... .... .... = IG bit: Individual address (unicast)
        .... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
    Source: Vmware_d2:6a:2a (00:0c:29:d2:6a:2a)
        Address: Vmware_d2:6a:2a (00:0c:29:d2:6a:2a)
        .... ...0 .... .... .... .... = IG bit: Individual address (unicast)
        .... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
    Type: IP (0x0800)
Internet Protocol, Src: 192.168.2.11 (192.168.2.11), Dst: 192.168.2.141 (192.168.2.141)
    Version: 4
    Header length: 20 bytes
    Differentiated Services Field: 0x00 (DSCP 0x00: Default; ECN: 0x00)
        0000 00.. = Differentiated Services Codepoint: Default (0x00)
        .... ..0. = ECN-Capable Transport (ECT): 0
        .... ...0 = ECN-CE: 0
    Total Length: 622
    Identification: 0x504d (20557)
    Flags: 0x04 (Don't Fragment)
        0... = Reserved bit: Not set
        .1.. = Don't fragment: Set
        ..0. = More fragments: Not set
    Fragment offset: 0
    Time to live: 64
    Protocol: UDP (0x11)
    Header checksum: 0x6249 [correct]
        [Good: True]
        [Bad : False]
    Source: 192.168.2.11 (192.168.2.11)
    Destination: 192.168.2.141 (192.168.2.141)
User Datagram Protocol, Src Port: 10538 (10538), Dst Port: dsmeter_iatc (4060)
    Source port: 10538 (10538)
    Destination port: dsmeter_iatc (4060)
    Length: 602
    Checksum: 0xf199 [correct]
        [Good Checksum: True]
        [Bad Checksum: False]
Session Initiation Protocol
    Request-Line: ACK sip:subs000663 at 192.168.2.11:7663;transport=UDP SIP/2.0
        Method: ACK
        [Resent Packet: False]
    Message Header
        Via: SIP/2.0/UDP 192.168.2.11:10538;branch=z9hG4bK-3501-49-4
            Transport: UDP
            Sent-by Address: 192.168.2.11
            Sent-by port: 10538
            Branch: z9hG4bK-3501-49-4
        Max-Forwards: 70
        [truncated] Route:  <sip:192.168.2.141;lr;ftag=3501SIPpTag0049>, <sip:mo at pcscf.open-ims.test:4060;lr>, <sip:mo at scscf.open-ims.test:6060;lr>, <sip:mt at scscf.open-ims.test:6060;lr>, <sip:mt at pcscf.open-ims.test:4060;lr>,<sip:192.168.2.141;lr;f
        From: "subs003538" <sip:subs003538 at open-ims.test>;tag=3501SIPpTag0049
            SIP Display info: "subs003538" 
            SIP from address: sip:subs003538 at open-ims.test
            SIP tag: 3501SIPpTag0049
        To: "subs000663" <sip:subs000663 at open-ims.test>;tag=3501SIPpTag0150
            SIP Display info: "subs000663" 
            SIP to address: sip:subs000663 at open-ims.test
            SIP tag: 3501SIPpTag0150
        Call-ID: 49-3501 at 192.168.2.11
        CSeq: 1 ACK
            Sequence Number: 1
            Method: ACK
        Content-Length: 0


________________________________
 From: Bogdan-Andrei Iancu <bogdan at opensips.org>
To: Kaan Dandin <kaandandin at yahoo.com>; OpenSIPS users mailling list <users at lists.opensips.org> 
Cc: Gunes Kurt <gkurt at itu.edu.tr>; "Ibrahim Hokelek, (BİLGEM-UEKAE)" <ibrahim.hokelek at tubitak.gov.tr> 
Sent: Wednesday, October 15, 2014 10:22 AM
Subject: Re: YNT: Re: YNT: Re: YNT: Re: [OpenSIPS-Users] RFC3261 transaction matching failed error for the second 401 Unauthorized - Challenging the UE
 


Hi Kaan,

I'm glad the first part is properly working now.

Your ACK (as it is for a 200 OK) should be routed based on Route
      headers (record route  and loose route mechanism). TO better
      understand this, please take a look to this webinar:
    http://www.opensips.org/Documentation/Webinars#toc12   ( chapter 5.5 )

At INVITE time you should do record_route() and the ACK should
      carry the Route headers in order to follow the same path as the
      INVITE.

Regards,

Bogdan-Andrei Iancu
OpenSIPS Founder and Developer http://www.opensips-solutions.com
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20141015/5b8b37f9/attachment-0001.htm>


More information about the Users mailing list