[OpenSIPS-Devel] [ opensips-Bugs-2391787 ] Error in sending NOTIFY for refresh SUBSCRIBE in RLS module

Tue Dec 9 13:40:37 CET 2008

Bugs item #2391787, was opened at 2008-12-05 08:03
Message generated for change (Comment added) made by anca_vamanu
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=2391787&group_id=232389

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: modules
Group: trunk
Status: Open
Resolution: Wont Fix
Priority: 9
Private: No
Submitted By: Nathan (rmnathan)
Assigned to: Anca Vamanu (anca_vamanu)
Summary: Error in sending NOTIFY for refresh SUBSCRIBE in RLS module

Initial Comment:
Version = trunk build
Module = RLS

The NOTIFY msg for refresh subscribe is sending directly to UE instead of sending to proxy in RLS mode. In that Route header is missing.

Initial subscribe 
==================
1. Proxy to opensips

SUBSCRIBE sip:s3-1 at 10.6.2.246 SIP/2.0
Via: SIP/2.0/UDP 192.168.126.1:50602;branch=z9hG4bK+bf0d90f7f3edfa41d338960687825df3+s+1;X-ST-CID=21011
Via: SIP/2.0/UDP 192.168.126.151:60000;branch=z9hG4bK-s3-114461640680
P-Charging-Vector: icid-value=starent.coms3-1-80
Route: <sip:10.6.2.246:5060;lr>
Expires: 200
Event: presence
Accept: application/rlmi+xml
Accept: multipart/related
Accept: application/pidf+xml
Supported: eventlist
From: sip:s3-1 at 10.6.2.246;tag=59572288
To: sip:s3-1 at 10.6.2.246
P-Asserted-Identity: <sip:s3-1 at 10.6.2.246>
Record-Route: <sip:192.168.126.1:50602;lr>;X-DC-TM-IDX=1;X-ST-CID=21011
Record-Route: <sip:192.168.126.1:50602;lr>;X-DC-TM-IDX=1;X-ST-CID=20002;X-ST-DLG-ID=536870913
Call-ID: s3-1-80
CSeq: 1 SUBSCRIBE
Contact: <sip:s3-1 at 192.168.126.151:60000>
Content-Length: 0
Max-Forwards: 69

2. Notify for initial subscribe (opensips to proxy)

NOTIFY sip:s3-1 at 192.168.126.151:60000 SIP/2.0
Via: SIP/2.0/UDP 10.6.2.246;branch=z9hG4bKaa48.106098f2.0
To: sip:s3-1 at 10.6.2.246;tag=59572288
From: sip:s3-1 at 10.6.2.246;tag=97b57f2144c425bc44f2e7a21eb22549-b818
CSeq: 1 NOTIFY
Call-ID: s3-1-80
Route: <sip:192.168.126.1:50602;lr>;X-DC-TM-IDX=1;X-ST-CID=21011,
       <sip:192.168.126.1:50602;lr>;X-DC-TM-IDX=1;X-ST-CID=20002;X-ST-DLG-ID=536870913
Content-Length: 375
User-Agent: OpenSIPS (1.5.0dev2-notls (i386/linux))
Max-Forwards: 70
Event: presence
Contact: <sip:10.6.2.246:5060;transport=udp>
Subscription-State: active;expires=200
Require: eventlist
Content-Type: multipart/related;type="application/rlmi+xml";start= "<1228453070.sip:s3-1 at 10.6.2.246.1463319679>";boundary="Fk3QCGTvdTGnGmVrrm5wBXef"

--Fk3QCGTvdTGnGmVrrm5wBXef
Content-Transfer-Encoding: binary
Content-ID: <1228453070.sip:s3-1 at 10.6.2.246.1463319679>
Content-Type: application/rlmi+xml;charset="UTF-8r"

<?xml version="1.0"?>
<list uri="sip:s3-1 at 10.6.2.246" xmlns="urn:ietf:params:xml:ns:rlmi" version="1" fullState="true">
  <resource uri="sip:c3-1 at 10.6.2.246"/>
</list>

--Fk3QCGTvdTGnGmVrrm5wBXef--

Refresh Subscribe 
===================
1. Proxy to opensips

SUBSCRIBE sip:10.6.2.246:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.126.1:50602;branch=z9hG4bK+bd987cb1d4b434a184c0ad66fe527ebc+s+1;X-ST-CID=21013
Via: SIP/2.0/UDP 192.168.126.151:60000;branch=z9hG4bK-s3-114224888240
P-Charging-Vector: icid-value=starent.coms3-1-80
Expires: 200
Event: presence
Accept: application/rlmi+xml
Accept: multipart/related
Accept: application/pidf+xml
Supported: eventlist
From: sip:s3-1 at 10.6.2.246;tag=59572288
To: sip:s3-1 at 10.6.2.246;tag=97b57f2144c425bc44f2e7a21eb22549-b818
P-Asserted-Identity: <sip:s3-1 at 10.6.2.246>
Call-ID: s3-1-80
CSeq: 2 SUBSCRIBE
Contact: <sip:s3-1 at 192.168.126.151:60000>
Content-Length: 0
Max-Forwards: 69

2. Notify for Refresh subscribe (opensips to proxy)

Issue:
=====
Here Notification is sending directly to UE. No route header has added. 
Opensips should send to proxy.
Finally lot of re transmission happened for NOTIFY (for not getting 200 ok )

Dec  4 23:58:11 [26262] DBG:tm:utimer_routine: timer routine:4,tl=0xb5b012fc next=0xb5afbefc, timeout=46500000
Dec  4 23:58:11 [26262] DBG:tm:retransmission_handler: retransmission_handler : request resending (t=0xb5b011a0, NOTIFY si ... )
Dec  4 23:58:11 [26262] DBG:tm:set_timer: relative timeout is 1000000
Dec  4 23:58:11 [26262] DBG:tm:insert_timer_unsafe: [5]: 0xb5b012fc (47500000)
Dec  4 23:58:11 [26262] DBG:tm:retransmission_handler: retransmission_handler : done
Dec  4 23:58:11 [26262] DBG:tm:utimer_routine: timer routine:4,tl=0xb5afbefc next=(nil), timeout=46500000
Dec  4 23:58:11 [26262] DBG:tm:utimer_routine: timer routine:4,tl=0xb5afe5ec next=(nil), timeout=46600000
Dec  4 23:58:12 [26262] DBG:tm:utimer_routine: timer routine:5,tl=0xb5b012fc next=(nil), timeout=47500000
Dec  4 23:58:12 [26262] DBG:tm:retransmission_handler: retransmission_handler : request resending (t=0xb5b011a0, NOTIFY si ... )
Dec  4 23:58:12 [26262] DBG:tm:set_timer: relative timeout is 2000000
Dec  4 23:58:12 [26262] DBG:tm:insert_timer_unsafe: [6]: 0xb5b012fc (49500000)
Dec  4 23:58:12 [26262] DBG:tm:retransmission_handler: retransmission_handler : done
Dec  4 23:58:14 [26262] DBG:tm:utimer_routine: timer routine:6,tl=0xb5b012fc next=(nil), timeout=49500000
Dec  4 23:58:14 [26262] DBG:tm:retransmission_handler: retransmission_handler : request resending (t=0xb5b011a0, NOTIFY si ... )
Dec  4 23:58:14 [26262] DBG:tm:set_timer: relative timeout is 4000000
Dec  4 23:58:14 [26262] DBG:tm:insert_timer_unsafe: [7]: 0xb5b012fc (53500000)
Dec  4 23:58:14 [26262] DBG:tm:retransmission_handler: retransmission_handler : done

NOTIFY sip:s3-1 at 192.168.126.151:60000 SIP/2.0^M
Via: SIP/2.0/UDP 10.6.2.246;branch=z9hG4bK7a48.974c01c7.0^M
To: sip:s3-1 at 10.6.2.246;tag=59572288^M
From: sip:s3-1 at 10.6.2.246;tag=97b57f2144c425bc44f2e7a21eb22549-b818^M
CSeq: 2 NOTIFY^M
Call-ID: s3-1-80^M
Content-Length: 375^M
User-Agent: OpenSIPS (1.5.0dev2-notls (i386/linux))^M
Max-Forwards: 70^M
Event: presence^M
Contact: <sip:10.6.2.246:5060;transport=udp>^M
Subscription-State: active;expires=200^M
Require: eventlist^M
Content-Type: multipart/related;type="application/rlmi+xml";start= "<1228453091.sip:s3-1 at 10.6.2.246.1092908929>";boundary="ysnG2GAKNcGvKOj5Zeqlnwvx"^M
^M
--ysnG2GAKNcGvKOj5Zeqlnwvx^M
Content-Transfer-Encoding: binary^M
Content-ID: <1228453091.sip:s3-1 at 10.6.2.246.1092908929>^M
Content-Type: application/rlmi+xml;charset="UTF-8r"^M
^M
<?xml version="1.0"?>
<list uri="sip:s3-1 at 10.6.2.246" xmlns="urn:ietf:params:xml:ns:rlmi" version="2" fullState="true">
  <resource uri="sip:c3-1 at 10.6.2.246"/>
</list>
^M
--ysnG2GAKNcGvKOj5Zeqlnwvx--

----------------------------------------------------------------------

>Comment By: Anca Vamanu (anca_vamanu)
Date: 2008-12-09 14:40

Message:
Hi Nathan,

I have tested myself now(without calling record_route on in dialog
SUBSCRIBE) and it works. The Notify sent by the RLS server has the right
Route header and passes through the proxy.
Can you provide some trace on rls server for the subsequent Subscribe and
the triggered Notify?

regards,
Anca

----------------------------------------------------------------------

Comment By: Nathan (rmnathan)
Date: 2008-12-08 16:38

Message:
Hi Anca,
I have tested with latest trunk build. Iam getting the same error ( ie
opensips is sending NOTIFY message directly to UE for refresh SUBSCRIBE.). 

Regards,
Nathan

----------------------------------------------------------------------

Comment By: Anca Vamanu (anca_vamanu)
Date: 2008-12-08 13:45

Message:
Hi Nathan, 

Thank you for the report. Indeed there was a miss out there that lead to
only the route set from the received Subscribe to be added instead of the
route set from the initial subscribe. It is fixed now both in trunk and the
stable 1.4.x branch.

regards,
Anca

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=2391787&group_id=232389