[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 06:27:20 CEST 2014
Hi Bogdan,
Thanks a lot for your response. My aim is to register to both IMS nodes(.3 and .5) in the same time ,then able to make load balancing to any of them.
With your support ,now I better understand how t_relay and paralel forking is working.
I have managed the problem by sending to different IMS registration scenario (.3 and .5) from IMS bench (.11) instead of parallel forking in OpenSIPS.
Now the registrations are successuly completed.
But I have another problem in the IMS call scenario.
ACK messages are always going to .5 IMS node in t_relay instead of the related node. In the logs it seems that related transaction not found and address is found with DNS lookup and always sent to .5 node.
For that reason only half of the calls are successful.
Below I am sharing related part of the script , call flow and trace.
Kind regards,
Kaan
} else {
if ( is_method("ACK") ) {
xlog("xlog_ack_method");
if ( t_check_trans() ) {
# non loose-route, but stateful ACK; must be an ACK after
# a 487 or e.g. 404 from upstream server
xlog("xlog_nonlooseroutestatefulack");
t_relay();
exit;
} else {
# ACK without matching transaction ->
# ignore and discard
t_relay();
xlog("xlog_nonlooseroutenonstatefulack");
exit;
}
}
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
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: xlog method: [ACK] totag: [69bab173779e29f3a0c2aaef4e939266-4eaf] sipid: [192.168.2.5] messageid: [898] callid: [54-3946 at 192.168.2.11] callsequence: [1]
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:uri:has_totag: totag found
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: xlog_has_totag
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:parse_headers: flags=200
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:get_hdr_field: content_length=0
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:get_hdr_field: found end of header
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:rr:find_first_route: No Route headers found
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:rr:loose_route: There is no Route HF
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: xlog_ack_method
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:parse_headers: flags=78
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:tm:t_lookup_request: start searching: hash=36408, isACK=1
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:tm:t_lookup_request: proceeding to pre-RFC3261 transaction matching
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:tm:t_lookup_request: no transaction found
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:tm:t_newtran: transaction on entrance=(nil)
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:parse_headers: flags=ffffffffffffffff
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:tm:t_relay_to: forwarding ACK
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:mk_proxy: doing DNS lookup...
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:parse_headers: flags=ffffffffffffffff
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:check_ip_address: params 192.168.2.5, 192.168.2.5, 0
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:forward_request: sending:#012ACK sip:subs000423 at 192.168.2.11:7423 SIP/2.0#015#012Max-Forwards: 10#015#012Via: SIP/2.0/UDP 192.168.2.141:4060;branch=z9hG4bK83e8.fcacb1c3.0#015#012Via: SIP/2.0/UDP 192.168.2.5:4060;branch=0#015#012Via: SIP/2.0/UDP 192.168.2.5:6060;rport=6060;branch=z9hG4bK83e8.fcacb1c3.0#015#012From: "subs004934" <sip:subs004934 at open-ims.test>;tag=3946SIPpTag0054#015#012Call-ID: 54-3946 at 192.168.2.11#015#012To: "subs000423" <sip:subs000423 at open-ims.test>;tag=69bab173779e29f3a0c2aaef4e939266-4eaf#015#012CSeq: 1 ACK#015#012User-Agent: Sip EXpress router(2.1.0-dev1 OpenIMSCore (i386/linux))#015#012Content-Length: 0#015#012#015#012.
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:forward_request: orig. len=480, new_len=547, proto=1
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: xlog_nonlooseroutenonstatefulack
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:destroy_avp_list: destroying list (nil)
Oct 14 11:45:03 ubuntu /usr/local/opensips/sbin/opensips[6068]: DBG:core:receive_msg: cleaning up
4 INVITE ----------> B1,2,4 21 0 0
5 100 <---------- 21 0 0
6 180 <---------- 21 0 0
7 183 <---------- 0 0 0
8 200 <---------- 21 33 0
9 ACK ----------> 21 33
10 180 <---------- 0 0 0
11 Pause [Exp(2:00)] 21 0
12 BYE ----------> B3 21 99 11
13 180 <---------- 0 0 0
14 200 <---------- E3,4 10 0 110
15 [ RECVRMT ] 10 0
1- ims_uac-0- Statistics Screen - [1-9]: Change Screen - 4485
Start Time | 2014-10-14 14:59:55
Last Reset Time | 2014-10-14 15:01:50
Current Time | 2014-10-14 15:01:51
-------------------------+---------------------------+--------------------------
Counter Name | Periodic value | Cumulative value
-------------------------+---------------------------+--------------------------
Elapsed Time | 00:00:00:349 | 00:01:55:109
Call Rate | 0.000 cps | 0.182 cps
-------------------------+---------------------------+--------------------------
Incoming call created | 0 | 0
OutGoing call created | 0 | 21
Total Call created | | 21
Current Call | 0 |
-------------------------+---------------------------+--------------------------
Successful call | 0 | 10
Failed call | 1 | 11
-------------------------+---------------------------+--------------------------
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: Tuesday, October 14, 2014 6:50 PM
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,
When you do parallel forking (sending same request to two
destinations), only one negative reply (from the two branches)
is sent back to caller (to .11 in your case). You get the 401
reply on both .3 and .5 branches and OpenSIPS picks one to be
sent to caller .11 (in SIP only one SIP negative reply per
request is allowed).
So, from SIP perspective it works ok, but my impression is you
want something else.
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/20141014/fd7be9d8/attachment-0001.htm>
More information about the Users
mailing list