while doing some presence tests with master i noticed that when presence server sends notify that terminates subscription due to change in xcap authorization rules, cseq in the notify is same as in previous one.
rfc3261 says in 12.2.1 UAC Behavior:
Requests within a dialog MUST contain strictly monotonically increasing and contiguous CSeq sequence numbers (increasing-by-one) in each direction (excepting ACK and CANCEL of course, whose numbers equal the requests being acknowledged or cancelled).
so this looks like a bug to twinkle (and me). below is sip debug from twinkle (subscriber).
-- juha
+++ 2-5-2012 08:50:41.158705 INFO SIP ::process_sip_msg Received from: tcp:192.98.103.10:5060 NOTIFY sip:jh@192.98.103.10:5074;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.98.103.10;branch=z9hG4bK4da2.6447f6ae08e84f0c0fbec6f7090757cc.0;i=c1 Via: SIP/2.0/TCP 127.0.0.1:5082;branch=z9hG4bK4da2.4e788af3000000000000000000000000.0 To: sip:jh@test.fi;tag=pqazy From: sip:test@test.fi;tag=4a664ec84c547b2d0bc0fe8965f834e4-8a4b CSeq: 2 NOTIFY Call-ID: byxobtomskpzmos@siika.tutpro.com Content-Length: 210 User-Agent: OpenXg Presence/XCAP Server (3.3.0-dev8 (x86_64/linux)) Max-Forwards: 69 Event: presence Contact: sip:127.0.0.1:5082;alias=127.0.0.1~35306~2;transport=tcp Subscription-State: active;expires=3670 Content-Type: application/pidf+xml
<?xml version="1.0" encoding="UTF-8"?> <presence xmlns="urn:ietf:params:xml:ns:pidf" entity="sip:test@test.fi"> <tuple id="gxsdoz"> <status> <basic>open</basic> </status> </tuple> </presence>
---
+++ 2-5-2012 08:50:41.161169 INFO SIP ::send_sip_tcp Send to: tcp:192.98.103.10:5060 SIP/2.0 200 OK Via: SIP/2.0/TCP 192.98.103.10;branch=z9hG4bK4da2.6447f6ae08e84f0c0fbec6f7090757cc.0;i=c1,SIP/2.0/TCP 127.0.0.1:5082;branch=z9hG4bK4da2.4e788af3000000000000000000000000.0 To: sip:jh@test.fi;tag=pqazy From: sip:test@test.fi;tag=4a664ec84c547b2d0bc0fe8965f834e4-8a4b Call-ID: byxobtomskpzmos@siika.tutpro.com CSeq: 2 NOTIFY Server: Twinkle/1.4.2 Content-Length: 0
---
+++ 2-5-2012 08:51:00.381465 INFO SIP ::process_sip_msg Received from: tcp:192.98.103.10:5060 NOTIFY sip:jh@192.98.103.10:5074;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.98.103.10;branch=z9hG4bK4da2.fd70b43b9da3c3b488208a61595b1112.0;i=c1 Via: SIP/2.0/TCP 127.0.0.1:5082;branch=z9hG4bK4da2.444a74e2000000000000000000000000.0 To: sip:jh@test.fi;tag=pqazy From: sip:test@test.fi;tag=4a664ec84c547b2d0bc0fe8965f834e4-8a4b CSeq: 2 NOTIFY Call-ID: byxobtomskpzmos@siika.tutpro.com Content-Length: 0 User-Agent: OpenXg Presence/XCAP Server (3.3.0-dev8 (x86_64/linux)) Max-Forwards: 69 Event: presence Contact: sip:127.0.0.1:5082;alias=127.0.0.1~35306~2;transport=tcp Subscription-State: terminated;reason=terminated
---
+++ 2-5-2012 08:51:00.381794 WARNING NORMAL t_subscription_dialog::recvd_request CSeq seqnr is out of sequence. Reveived seqnr: 2 Remote seqnr: 2
Hi,
There are lots of CSeq race conditions when subs_db_mode is DB only. I am working on adding separate notifier processes to presence which, amongst other things, will fix this.
I had intended to get this into master last week, but other stuff came up and the development has been a bit more complicated than I'd hoped. I expect to commit these changes (which should fix your problem) sometime over the next week.
Peter
On Wed, 2012-05-02 at 09:20 +0300, Juha Heinanen wrote:
while doing some presence tests with master i noticed that when presence server sends notify that terminates subscription due to change in xcap authorization rules, cseq in the notify is same as in previous one.
rfc3261 says in 12.2.1 UAC Behavior:
Requests within a dialog MUST contain strictly monotonically increasing and contiguous CSeq sequence numbers (increasing-by-one) in each direction (excepting ACK and CANCEL of course, whose numbers equal the requests being acknowledged or cancelled).
so this looks like a bug to twinkle (and me). below is sip debug from twinkle (subscriber).
-- juha
+++ 2-5-2012 08:50:41.158705 INFO SIP ::process_sip_msg Received from: tcp:192.98.103.10:5060 NOTIFY sip:jh@192.98.103.10:5074;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.98.103.10;branch=z9hG4bK4da2.6447f6ae08e84f0c0fbec6f7090757cc.0;i=c1 Via: SIP/2.0/TCP 127.0.0.1:5082;branch=z9hG4bK4da2.4e788af3000000000000000000000000.0 To: sip:jh@test.fi;tag=pqazy From: sip:test@test.fi;tag=4a664ec84c547b2d0bc0fe8965f834e4-8a4b CSeq: 2 NOTIFY Call-ID: byxobtomskpzmos@siika.tutpro.com Content-Length: 210 User-Agent: OpenXg Presence/XCAP Server (3.3.0-dev8 (x86_64/linux)) Max-Forwards: 69 Event: presence Contact: sip:127.0.0.1:5082;alias=127.0.0.1~35306~2;transport=tcp Subscription-State: active;expires=3670 Content-Type: application/pidf+xml
<?xml version="1.0" encoding="UTF-8"?>
<presence xmlns="urn:ietf:params:xml:ns:pidf" entity="sip:test@test.fi">
<tuple id="gxsdoz"> <status> <basic>open</basic> </status> </tuple> </presence>
+++ 2-5-2012 08:50:41.161169 INFO SIP ::send_sip_tcp Send to: tcp:192.98.103.10:5060 SIP/2.0 200 OK Via: SIP/2.0/TCP 192.98.103.10;branch=z9hG4bK4da2.6447f6ae08e84f0c0fbec6f7090757cc.0;i=c1,SIP/2.0/TCP 127.0.0.1:5082;branch=z9hG4bK4da2.4e788af3000000000000000000000000.0 To: sip:jh@test.fi;tag=pqazy From: sip:test@test.fi;tag=4a664ec84c547b2d0bc0fe8965f834e4-8a4b Call-ID: byxobtomskpzmos@siika.tutpro.com CSeq: 2 NOTIFY Server: Twinkle/1.4.2 Content-Length: 0
+++ 2-5-2012 08:51:00.381465 INFO SIP ::process_sip_msg Received from: tcp:192.98.103.10:5060 NOTIFY sip:jh@192.98.103.10:5074;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.98.103.10;branch=z9hG4bK4da2.fd70b43b9da3c3b488208a61595b1112.0;i=c1 Via: SIP/2.0/TCP 127.0.0.1:5082;branch=z9hG4bK4da2.444a74e2000000000000000000000000.0 To: sip:jh@test.fi;tag=pqazy From: sip:test@test.fi;tag=4a664ec84c547b2d0bc0fe8965f834e4-8a4b CSeq: 2 NOTIFY Call-ID: byxobtomskpzmos@siika.tutpro.com Content-Length: 0 User-Agent: OpenXg Presence/XCAP Server (3.3.0-dev8 (x86_64/linux)) Max-Forwards: 69 Event: presence Contact: sip:127.0.0.1:5082;alias=127.0.0.1~35306~2;transport=tcp Subscription-State: terminated;reason=terminated
+++ 2-5-2012 08:51:00.381794 WARNING NORMAL t_subscription_dialog::recvd_request CSeq seqnr is out of sequence. Reveived seqnr: 2 Remote seqnr: 2
sr-dev mailing list sr-dev@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
Peter Dunkley writes:
There are lots of CSeq race conditions when subs_db_mode is DB only. I am working on adding separate notifier processes to presence which, amongst other things, will fix this.
peter,
nice to hear. in my test i had not set subs_db_mode, which means Write-Back scheme. also, i don't think that in this test race conditions play any role, because time difference between the two notifies was 19 seconds. looks to me the this bug is of more fundamental nature.
-- juha
OK.
Well the fix I am doing will completely alter the mechanism for generating NOTIFYs when subs_db_mode is DB only and a couple of other parameters are set. However, I am deliberately leaving the existing behaviour unchanged for other modes. So it sounds like there is a problem here, but not one my work will fix.
Peter
On Wed, 2012-05-02 at 12:15 +0300, Juha Heinanen wrote:
Peter Dunkley writes:
There are lots of CSeq race conditions when subs_db_mode is DB only. I am working on adding separate notifier processes to presence which, amongst other things, will fix this.
peter,
nice to hear. in my test i had not set subs_db_mode, which means Write-Back scheme. also, i don't think that in this test race conditions play any role, because time difference between the two notifies was 19 seconds. looks to me the this bug is of more fundamental nature.
-- juha
sr-dev mailing list sr-dev@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
Peter Dunkley writes:
Well the fix I am doing will completely alter the mechanism for generating NOTIFYs when subs_db_mode is DB only and a couple of other parameters are set. However, I am deliberately leaving the existing behaviour unchanged for other modes. So it sounds like there is a problem here, but not one my work will fix.
fair enough. if there is no interest by some else to maintain the other modes then they could be removed altogether.
-- juha
Hello,
On 5/2/12 11:30 AM, Juha Heinanen wrote:
Peter Dunkley writes:
Well the fix I am doing will completely alter the mechanism for generating NOTIFYs when subs_db_mode is DB only and a couple of other parameters are set. However, I am deliberately leaving the existing behaviour unchanged for other modes. So it sounds like there is a problem here, but not one my work will fix.
fair enough. if there is no interest by some else to maintain the other modes then they could be removed altogether.
there is intent to maintain such modes, at least until ones proved to be better. This looks like a bug, just open an issue on the tracker to have it in mind for this period of testing. If none fixes it, at some point I will get to it.
Cheers, Daniel
Juha Heinanen writes:
while doing some presence tests with master i noticed that when presence server sends notify that terminates subscription due to change in xcap authorization rules, cseq in the notify is same as in previous one.
i tried again with DB only mode
modparam("presence", "subs_db_mode", 3)
and the result was the same, i.e., cseq was not incremented in the second notify.
-- juha
That's the least of what happens in DB only mode if you apply some load :-)
On Wed, 2012-05-02 at 13:37 +0300, Juha Heinanen wrote:
Juha Heinanen writes:
while doing some presence tests with master i noticed that when presence server sends notify that terminates subscription due to change in xcap authorization rules, cseq in the notify is same as in previous one.
i tried again with DB only mode
modparam("presence", "subs_db_mode", 3)
and the result was the same, i.e., cseq was not incremented in the second notify.
-- juha
sr-dev mailing list sr-dev@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
Hi Juha,
I have investigated what you reported and indeed there was a bug with wrong Cseq in Notify with expires=0 triggered by another event than the receipt of a Subscribe present only in a db_mode!=DB_ONLY.
While testing I also found a problem with the expires parameter value in the Subscription-Status header. There was a static buffer used twice when building the extra headers and as a consequence this expires value always had the last two digits '70'.
I have fixed these two problem in commit cd1ff5364786f8b32058921be6f3216b48e34792. Please test and let me know the results.
Regards, Anca
On 05/02/2012 09:20 AM, Juha Heinanen wrote:
while doing some presence tests with master i noticed that when presence server sends notify that terminates subscription due to change in xcap authorization rules, cseq in the notify is same as in previous one.
rfc3261 says in 12.2.1 UAC Behavior:
Requests within a dialog MUST contain strictly monotonically increasing and contiguous CSeq sequence numbers (increasing-by-one) in each direction (excepting ACK and CANCEL of course, whose numbers equal the requests being acknowledged or cancelled).so this looks like a bug to twinkle (and me). below is sip debug from twinkle (subscriber).
-- juha
+++ 2-5-2012 08:50:41.158705 INFO SIP ::process_sip_msg Received from: tcp:192.98.103.10:5060 NOTIFY sip:jh@192.98.103.10:5074;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.98.103.10;branch=z9hG4bK4da2.6447f6ae08e84f0c0fbec6f7090757cc.0;i=c1 Via: SIP/2.0/TCP 127.0.0.1:5082;branch=z9hG4bK4da2.4e788af3000000000000000000000000.0 To: sip:jh@test.fi;tag=pqazy From: sip:test@test.fi;tag=4a664ec84c547b2d0bc0fe8965f834e4-8a4b CSeq: 2 NOTIFY Call-ID: byxobtomskpzmos@siika.tutpro.com Content-Length: 210 User-Agent: OpenXg Presence/XCAP Server (3.3.0-dev8 (x86_64/linux)) Max-Forwards: 69 Event: presence Contact:sip:127.0.0.1:5082;alias=127.0.0.1~35306~2;transport=tcp Subscription-State: active;expires=3670 Content-Type: application/pidf+xml
<?xml version="1.0" encoding="UTF-8"?>
<presence xmlns="urn:ietf:params:xml:ns:pidf" entity="sip:test@test.fi">
<tuple id="gxsdoz"> <status> <basic>open</basic> </status> </tuple> </presence>
+++ 2-5-2012 08:50:41.161169 INFO SIP ::send_sip_tcp Send to: tcp:192.98.103.10:5060 SIP/2.0 200 OK Via: SIP/2.0/TCP 192.98.103.10;branch=z9hG4bK4da2.6447f6ae08e84f0c0fbec6f7090757cc.0;i=c1,SIP/2.0/TCP 127.0.0.1:5082;branch=z9hG4bK4da2.4e788af3000000000000000000000000.0 To:sip:jh@test.fi;tag=pqazy From:sip:test@test.fi;tag=4a664ec84c547b2d0bc0fe8965f834e4-8a4b Call-ID: byxobtomskpzmos@siika.tutpro.com CSeq: 2 NOTIFY Server: Twinkle/1.4.2 Content-Length: 0
+++ 2-5-2012 08:51:00.381465 INFO SIP ::process_sip_msg Received from: tcp:192.98.103.10:5060 NOTIFY sip:jh@192.98.103.10:5074;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.98.103.10;branch=z9hG4bK4da2.fd70b43b9da3c3b488208a61595b1112.0;i=c1 Via: SIP/2.0/TCP 127.0.0.1:5082;branch=z9hG4bK4da2.444a74e2000000000000000000000000.0 To: sip:jh@test.fi;tag=pqazy From: sip:test@test.fi;tag=4a664ec84c547b2d0bc0fe8965f834e4-8a4b CSeq: 2 NOTIFY Call-ID: byxobtomskpzmos@siika.tutpro.com Content-Length: 0 User-Agent: OpenXg Presence/XCAP Server (3.3.0-dev8 (x86_64/linux)) Max-Forwards: 69 Event: presence Contact:sip:127.0.0.1:5082;alias=127.0.0.1~35306~2;transport=tcp Subscription-State: terminated;reason=terminated
+++ 2-5-2012 08:51:00.381794 WARNING NORMAL t_subscription_dialog::recvd_request CSeq seqnr is out of sequence. Reveived seqnr: 2 Remote seqnr: 2
sr-dev mailing list sr-dev@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
Anca Vamanu writes:
I have investigated what you reported and indeed there was a bug with wrong Cseq in Notify with expires=0 triggered by another event than the receipt of a Subscribe present only in a db_mode!=DB_ONLY.
anca,
thanks for the fix. the bug was both in write back and db only modes and is now fixed in both.
-- juha
-
Anca Vamanu -
Daniel-Constantin Mierla -
Juha Heinanen -
Peter Dunkley