[OpenSIPS-Devel] [ opensips-Bugs-2796442 ] presence: active_watchers deletes data before "expires" time

Mon May 25 16:44:17 CEST 2009

Bugs item #2796442, was opened at 2009-05-25 16:00
Message generated for change (Comment added) made by ibc_sf
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=2796442&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: None
Priority: 5
Private: No
Submitted By: Iñaki Baz Castillo (ibc_sf)
Assigned to: Nobody/Anonymous (nobody)
Summary: presence: active_watchers deletes data before "expires" time

Initial Comment:
OpenSIPS trunk rev 5706.

Presence related configuration:
-----------
modparam("presence", "max_expires_publish", 100)
modparam("presence", "max_expires_subscribe", 140)
modparam("presence", "expires_offset", 5)
modparam("presence", "fallback2db", 1)
-----------

After several testing I'm sure that the presence module is removing entries from active_watchers table before the "expires" time.
Please, take a look to the following real trace:

#### 30004 is subscribes to itself (30004) and it's receiving NOTIFY's correctly:

U 2009/05/25 15:47:21.530093 PROXY:5060 -> CLIENT:58198
NOTIFY sip:30004 at CLIENT:58198 SIP/2.0 
Via: SIP/2.0/UDP PROXY;branch=z9hG4bK95ab.5b04a0d3.0 
Via: SIP/2.0/UDP PROXY:5070;rport=5070;received=PROXY;branch=z9hG4bK95ab.d43429f5.0 
To: <sip:30004 at domain.org>;tag=549581004 
From: <sip:30004 at domain.org>;tag=13b52bc3e9f25b251a1546eb57a3a45c-f79d 
CSeq: 9 NOTIFY 
Call-ID: 498522887 at 10.134.16.124 
Content-Length: 286 
User-Agent: OpenSIPS (1.6.0dev0-notls (x86_64/linux)) 
Max-Forwards: 69 
Event: presence 
Contact: <sip:presence at PROXY:5070> 
Subscription-State: active;expires=129 
Content-Type: application/pidf+xml 

<?xml version="1.0" encoding="UTF-8"?>
<presence xmlns="urn:ietf:params:xml:ns:pidf" entity="sip:30004 at domain.org">
<tuple id="azersdqre">
<status><basic>closed</basic></status>
<note/>
<contact priority="1">sip:30004 at domain.org</contact>
</tuple>
</presence>

#
U 2009/05/25 15:47:21.537056 CLIENT:58198 -> PROXY:5060
SIP/2.0 100 Trying 
Via: SIP/2.0/UDP PROXY;branch=z9hG4bK95ab.5b04a0d3.0 
Via: SIP/2.0/UDP PROXY:5070;rport=5070;received=PROXY;branch=z9hG4bK95ab.d43429f5.0 
From: <sip:30004 at domain.org>;tag=13b52bc3e9f25b251a1546eb57a3a45c-f79d 
To: <sip:30004 at domain.org>;tag=549581004 
Call-ID: 498522887 at 10.134.16.124 
CSeq: 9 NOTIFY 
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, MESSAGE, INFO, REFER 
Content-Length: 0 

U 2009/05/25 15:47:26.536018 CLIENT:58198 -> PROXY:5060
SIP/2.0 200 OK 
Via: SIP/2.0/UDP PROXY;branch=z9hG4bK95ab.5b04a0d3.0 
Via: SIP/2.0/UDP PROXY:5070;rport=5070;received=PROXY;branch=z9hG4bK95ab.d43429f5.0 
From: <sip:30004 at domain.org>;tag=13b52bc3e9f25b251a1546eb57a3a45c-f79d 
To: <sip:30004 at domain.org>;tag=549581004 
Call-ID: 498522887 at 10.134.16.124 
CSeq: 9 NOTIFY 
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, MESSAGE, INFO, REFER 
Content-Length: 0 

### Note that the above NOTIFY has "expires=129" (time = 15:47:21)

### After some seconds, the client changes its presence status and sends a PUBLISH:

U 2009/05/25 15:47:34.247389 CLIENT:58198 -> PROXY:5060
PUBLISH sip:30004 at domain.org SIP/2.0 
Via: SIP/2.0/UDP 10.134.16.124:5060;rport;branch=z9hG4bK1904795625 
From: <sip:30004 at domain.org>;tag=1301576530 
To: <sip:30004 at domain.org> 
Call-ID: 2135969787 at 10.134.16.124 
CSeq: 21 PUBLISH 
Contact: <sip:30004 at 10.134.16.124:5060> 
Max-Forwards: 70 
User-Agent: qutecom/revb9d37dbd4b26/trunk/ 
Event: presence 
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, REFER, SUBSCRIBE, NOTIFY, MESSAGE 
Content-Type: application/pidf+xml 
Content-Length:   296 

<?xml version="1.0" encoding="UTF-8"?>
<presence xmlns="urn:ietf:params:xml:ns:pidf"
entity="sip:30004 at domain.org">
<tuple id="azersdqre">
<status><basic>open</basic></status>
<note>online</note>
<contact priority="1">sip:30004 at domain.org</contact>
</tuple>
</presence>

#
U 2009/05/25 15:47:34.249011 PROXY:5060 -> CLIENT:58198
SIP/2.0 200 OK 
Via: SIP/2.0/UDP 10.134.16.124:5060;received=CLIENT;rport=58198;branch=z9hG4bK1904795625 
From: <sip:30004 at domain.org>;tag=1301576530 
To: <sip:30004 at domain.org>;tag=13b52bc3e9f25b251a1546eb57a3a45c-8e7e 
Call-ID: 2135969787 at 10.134.16.124 
CSeq: 21 PUBLISH 
Expires: 95 
SIP-ETag: a.1243257770.21790.6.0 
Server: OpenSIPS (1.6.0dev0-notls (x86_64/linux)) 
Content-Length: 0 

#### And now, there is **NO** NOTIFY!!!
#### It doesn't make sense since the previous NOTIFY (15:47:21) said (expires=129)
#### and the new PUBLISH is at 15:47:34 (just 23 seconds after the previous NOTIFY).
#### I can sure that at this time the subscription has been deleted in the "active_watchers" 
#### table so this must be an error.

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

>Comment By: Iñaki Baz Castillo (ibc_sf)
Date: 2009-05-25 16:44

Message:
Humm, maybe it's a bug in the refresh SUBSCRIBE from the boggus Qutecom
softphone (I think I didn't capture SUSBCRIBE in the ngrep filter...).
It just *doesn't* happen at all with Twinkle. Let me re-check it please.

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

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