Presence.winfo resubscribe fails and Presence quits working

I am running OpenSIPS 1.5 with OpenXCAP 1.7 and also the latest version of Counterpath Bria Version 2.5 Build 52614

Presence works on the Bria client in the beginning. Client A is able to see client B's presence but after a while (40 minutes i think) it loses client B's presence.

I know this has something to do with the presence.winfo that is located in the "active_watchers" database table on OpenSIPS. I see the following error occur when I sniff the traffic.

SUBSCRIBE sip:opensips01.blahblah.com:5060 SIP/2.0
Via: SIP/2.0/UDP 10.9.13.11:61820;branch=z9hG4bK-d8754z-2be54fbb19599fb4-1---d8754z-;rport
Max-Forwards: 70
Contact: <sip:clienta@10.9.13.11:61820>
To: <sip:clienta@blahblah.com>;tag=3838fe1a5f62cf35f8f309b8bdd38b91-f91f
From: "Client A"<sip:clienta@blahblah.com>;tag=a293a0a4
Call-ID: ZDkxZDRlNGYzYzUyMmZhYmIzNjlkZGFiZDI5ZGVjMDc.
CSeq: 3 SUBSCRIBE
Expires: 3600
User-Agent: Bria release 2.5 stamp 52614
Event: presence.winfo
Content-Length: 0


SIP/2.0 404 Not here
Via: SIP/2.0/UDP 10.9.13.11:61820;branch=z9hG4bK-d8754z-2be54fbb19599fb4-1---d8754z-;rport=61820
To: <sip:clienta@blahblah.com>;tag=3838fe1a5f62cf35f8f309b8bdd38b91-f91f
From: "Client A"<sip:clienta@blahblah.com>;tag=a293a0a4
Call-ID: ZDkxZDRlNGYzYzUyMmZhYmIzNjlkZGFiZDI5ZGVjMDc.
CSeq: 3 SUBSCRIBE
Server: OpenSIPS (1.5.0-notls (i386/linux))
Content-Length: 0



Here is how "active_watchers" table looks before this issue happens

+-----+------------------------+------------------+----------------+---------+------------+----------------+----------+---------------------------------------+----------+----------------------------------------------+------------+-------------+-------------------------------+--------------+------------+--------+--------+---------+-----------------------+--------------------------------+
| id | presentity_uri | watcher_username | watcher_domain | to_user | to_domain | event | event_id | to_tag | from_tag | callid | local_cseq | remote_cseq | contact | record_route | expires | status | reason | version | socket_info | local_contact |
+-----+------------------------+------------------+----------------+---------+------------+----------------+----------+---------------------------------------+----------+----------------------------------------------+------------+-------------+-------------------------------+--------------+------------+--------+--------+---------+-----------------------+--------------------------------+
| 313 | sip:Clientb@blahblah.com | Clientb | blahblah.com | Clientb | blahblah.com | presence.winfo | | 3838fe1a5f62cf35f8f309b8bdd38b91-fb12 | bab04806 | Y2JmNmM3MWMzY2EzZWQ4MTdlODNhYjFmMjExYmNlNTI. | 1 | 1 | sip:Clientb@10.9.12.128:61278 | | 1239059512 | 1 | | 1 | udp:10.9.246.100:5060 | sip:opensips01.blahblah.com:5060 |
| 312 | sip:Clienta@blahblah.com | Clientb | blahblah.com | Clienta | blahblah.com | presence | | 3838fe1a5f62cf35f8f309b8bdd38b91-efde | 2a46e94b | MjQ0NTg1NzdkMDllYWE0MWI4NmZlZmZlMGJmNTdjYmI. | 2 | 1 | sip:Clientb@10.9.12.128:61278 | | 1239059512 | 1 | | 2 | udp:10.9.246.100:5060 | sip:opensips01.blahblah.com:5060 |
| 310 | sip:Clienta@blahblah.com | Clienta | blahblah.com | Clienta | blahblah.com | presence.winfo | | 3838fe1a5f62cf35f8f309b8bdd38b91-f91f | a293a0a4 | ZDkxZDRlNGYzYzUyMmZhYmIzNjlkZGFiZDI5ZGVjMDc. | 2 | 1 | sip:Clienta@10.9.13.11:61820 | | 1239058612 | 1 | | 2 | udp:10.9.246.100:5060 | sip:opensips01.blahblah.com:5060 |
| 311 | sip:Clientb@blahblah.com | Clienta | blahblah.com | Clientb | blahblah.com | presence | | 3838fe1a5f62cf35f8f309b8bdd38b91-6ab1 | 213e656c | NTY1ODk3NzNmMDI3YTY5MTBmNDJiNTdjMDdlOTZkMDg. | 8 | 1 | sip:Clienta@10.9.13.11:61820 | | 1239058612 | 1 | | 8 | udp:10.9.246.100:5060 | sip:opensips01.blahblah.com:5060 |
+-----+------------------------+------------------+----------------+---------+------------+----------------+----------+---------------------------------------+----------+----------------------------------------------+------------+-------------+-------------------------------+--------------+------------+--------+--------+---------+-----------------------+--------------------------------+



And here is "active_watchers" table after I see the issue from sniffing

+-----+------------------------+------------------+----------------+---------+------------+----------------+----------+---------------------------------------+----------+----------------------------------------------+------------+-------------+-------------------------------+--------------+------------+--------+--------+---------+-----------------------+--------------------------------+
| id | presentity_uri | watcher_username | watcher_domain | to_user | to_domain | event | event_id | to_tag | from_tag | callid | local_cseq | remote_cseq | contact | record_route | expires | status | reason | version | socket_info | local_contact |
+-----+------------------------+------------------+----------------+---------+------------+----------------+----------+---------------------------------------+----------+----------------------------------------------+------------+-------------+-------------------------------+--------------+------------+--------+--------+---------+-----------------------+--------------------------------+
| 313 | sip:clientb@blahblah.com | clientb | blahblah.com | clientb | blahblah.com | presence.winfo | | 3838fe1a5f62cf35f8f309b8bdd38b91-fb12 | bab04806 | Y2JmNmM3MWMzY2EzZWQ4MTdlODNhYjFmMjExYmNlNTI. | 1 | 1 | sip:clientb@10.9.12.128:61278 | | 1239059512 | 1 | | 1 | udp:10.9.246.100:5060 | sip:opensips01.blahblah.com:5060 |
| 312 | sip:clienta@blahblah.com | clientb | blahblah.com | clienta | blahblah.com | presence | | 3838fe1a5f62cf35f8f309b8bdd38b91-efde | 2a46e94b | MjQ0NTg1NzdkMDllYWE0MWI4NmZlZmZlMGJmNTdjYmI. | 2 | 1 | sip:clientb@10.9.12.128:61278 | | 1239059512 | 1 | | 2 | udp:10.9.246.100:5060 | sip:opensips01.blahblah.com:5060 |
+-----+------------------------+------------------+----------------+---------+------------+----------------+----------+---------------------------------------+----------+----------------------------------------------+------------+-------------+-------------------------------+--------------+------------+--------+--------+---------+-----------------------+--------------------------------+


Here is a debug from the Bria client

[09-04-06]17:50:52.558 | Info | RESIP:DUM | "requesting refresh of ClientRegistration sip:clienta@blahblah.com" |
[09-04-06]17:50:52.567 | Info | RESIP:DUM | "Got: SipResp: 401 tid=4fa63d739e932870 cseq=REGISTER / 3 from(wire)" |
[09-04-06]17:50:52.567 | Info | RESIP:DUM | "Refresh subscription: <sip:clienta@10.9.13.11:61820;addTransport>" |
[09-04-06]17:50:52.567 | Debug | CCM | "[has-body:F]SipReq: SUBSCRIBE opensips01.blahblah.com:5060 tid=23c7ac51f1a6d705 cseq=SUBSCRIBE contact=clienta@10.9.13.11:61820 / 3 from(tu)[clienta@blahblah.com -> clienta [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscription::onReadyToSend
[09-04-06]17:50:52.572 | Info | RESIP:DUM | "Got: SipResp: 404 tid=2be54fbb19599fb4 cseq=SUBSCRIBE / 3 from(wire)" |
[09-04-06]17:50:52.572 | Debug | CCM | "SipResp: 404 tid=2be54fbb19599fb4 cseq=SUBSCRIBE / 3 from(wire)[clienta@blahblah.com -> clienta [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscription::onTerminated
[09-04-06]17:50:52.572 | Debug | CCM | "[m_eUpdateResponseState:1][clienta@blahblah.com -> clienta [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscription::InternalShutdown
[09-04-06]17:50:52.572 | Debug | CCM | "[clienta@blahblah.com -> clienta [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionSession::InternalShutdown
[09-04-06]17:50:52.572 | Info | CCM | "Re-Subscribe NOT requested (m_ulInitialTimeBeforeReSubscribeInSeconds=0)[clienta@blahblah.com -> clienta [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionWatcher::OnSIPClientSubscriptionSessionDestroyed
[09-04-06]17:50:52.572 | Debug | CCM | "[clienta@blahblah.com -> clienta [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionWatcher::InternalShutdown
[09-04-06]17:50:52.572 | Debug | Contacts | "Winfo subscription terminated. Reason: 6, SIPResponseCode: 404, ResponseMessage: Not here" | sua::CWinfoDocSink::OnSIPClientSubscriptionTerminated
[09-04-06]17:50:52.573 | Debug | Contacts | "Winfo subscription session terminated. Reason: 6, SIPResponseCode: 404, ResponseMessage: Not here" | sua::CWinfoDocSink::OnSIPClientSubscriptionSessionTerminated
[09-04-06]17:50:52.577 | Info | RESIP:DUM | "Got: SipResp: 200 tid=ede67649a9f12987 cseq=REGISTER contact=clienta@10.9.13.11:61820 / 4 from(wire)" |
[09-04-06]17:50:52.593 | Info | RESIP:DUM | "Refresh subscription: <sip:clienta@10.9.13.11:61820;addTransport>" |
[09-04-06]17:50:52.593 | Debug | CCM | "[has-body:F]SipReq: SUBSCRIBE opensips01.blahblah.com:5060 tid=710d0703751bd8a0 cseq=SUBSCRIBE contact=clienta@10.9.13.11:61820 / 3 from(tu)[clienta@blahblah.com -> clientb [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscription::onReadyToSend
[09-04-06]17:50:52.593 | Info | RESIP:DUM | "Refresh subscription: <sip:clienta@10.9.13.11:61820;addTransport>" |
[09-04-06]17:50:52.593 | Debug | CCM | "[has-body:F]SipReq: SUBSCRIBE opensips01.blahblah.com:5060 tid=b689fa87274f1d71 cseq=SUBSCRIBE contact=clienta@10.9.13.11:61820 / 3 from(tu)[clienta@blahblah.com -> clientc [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscription::onReadyToSend
[09-04-06]17:50:52.597 | Info | RESIP:DUM | "Got: SipResp: 404 tid=59fae4e796557373 cseq=SUBSCRIBE / 3 from(wire)" |
[09-04-06]17:50:52.597 | Debug | CCM | "SipResp: 404 tid=59fae4e796557373 cseq=SUBSCRIBE / 3 from(wire)[clienta@blahblah.com -> clientb [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscription::onTerminated
[09-04-06]17:50:52.597 | Debug | CCM | "[m_eUpdateResponseState:1][clienta@blahblah.com -> clientb [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscription::InternalShutdown
[09-04-06]17:50:52.598 | Debug | CCM | "[clienta@blahblah.com -> clientb [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionSession::InternalShutdown
[09-04-06]17:50:52.598 | Info | CCM | "Will attempt to re-SUBSCRIBE in 300 sec.[clienta@blahblah.com -> clientb [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionWatcher::OnSIPClientSubscriptionSessionDestroyed
[09-04-06]17:50:52.598 | Debug | Contacts | "Presence change notification Buddy(DN:client b)" | sua::CABBuddy::setPresenceContent
[09-04-06]17:50:52.600 | Info | Contacts | "Buddy(DN:client b): Presence subscription terminated. Reason: 6, SIPResponseCode: 404, ResponseMessage: Not here" | sua::CABPresenceSinkSip::OnSIPClientSubscriptionTerminated
[09-04-06]17:50:52.600 | Debug | Contacts | "Pres subscription state change notification Buddy(DN:client b)" | sua::CABBuddy::setPresenceSubscriptionState
[09-04-06]17:50:52.600 | Debug | CCM | "[clienta@blahblah.com -> clientb [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionWatcher::TerminateClientSubscription
[09-04-06]17:50:52.600 | Debug | CCM | "[clienta@blahblah.com -> clientb [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionWatcher::InternalShutdown
[09-04-06]17:50:52.600 | Info | RESIP:DUM | "Got: SipResp: 404 tid=934e593a32e3ef8d cseq=SUBSCRIBE / 3 from(wire)" |
[09-04-06]17:50:52.600 | Debug | CCM | "SipResp: 404 tid=934e593a32e3ef8d cseq=SUBSCRIBE / 3 from(wire)[clienta@blahblah.com -> clientc [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscription::onTerminated
[09-04-06]17:50:52.600 | Debug | CCM | "[m_eUpdateResponseState:1][clienta@blahblah.com -> clientc [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscription::InternalShutdown
[09-04-06]17:50:52.601 | Debug | CCM | "[clienta@blahblah.com -> clientc [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionSession::InternalShutdown
[09-04-06]17:50:52.601 | Info | CCM | "Will attempt to re-SUBSCRIBE in 300 sec.[clienta@blahblah.com -> clientc [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionWatcher::OnSIPClientSubscriptionSessionDestroyed
[09-04-06]17:50:52.605 | Debug | Contacts | "Pres subscription state change notification Buddy(DN:client b)" | sua::CABBuddy::setPresenceSubscriptionState
[09-04-06]17:50:52.606 | Info | Contacts | "Buddy(DN:client b): Presence subscription session terminated. Reason: 0, SIPResponseCode: 0, ResponseMessage: " | sua::CABPresenceSinkSip::OnSIPClientSubscriptionSessionTerminated
[09-04-06]17:50:52.606 | Info | Contacts | "Buddy(DN:clientc Test): Presence subscription terminated. Reason: 6, SIPResponseCode: 404, ResponseMessage: Not here" | sua::CABPresenceSinkSip::OnSIPClientSubscriptionTerminated
[09-04-06]17:50:52.606 | Debug | Contacts | "Pres subscription state change notification Buddy(DN:clientc Test)" | sua::CABBuddy::setPresenceSubscriptionState
[09-04-06]17:50:52.606 | Debug | CCM | "[clienta@blahblah.com -> clientc [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionWatcher::TerminateClientSubscription
[09-04-06]17:50:52.606 | Debug | CCM | "[clienta@blahblah.com -> clientc [!at] blahblah.com (replace the [!at] with a @)]" | sua::CSIPClientSubscriptionWatcher::InternalShutdown
[09-04-06]17:50:52.607 | Debug | Contacts | "Pres subscription state change notification Buddy(DN:clientc Test)" | sua::CABBuddy::setPresenceSubscriptionState
[09-04-06]17:50:52.607 | Info | Contacts | "Buddy(DN:clientc Test): Presence subscription session terminated. Reason: 0, SIPResponseCode: 0, ResponseMessage: " | sua::CABPresenceSinkSip::OnSIPClientSubscriptionSessionTerminated
[09-04-06]17:50:52.614 | Info | RESIP:DUM | "Got: SipResp: 200 tid=12d45786b3eaad53 cseq=PUBLISH / 2 from(wire)" |
[09-04-06]17:50:52.614 | MaxDetails | CCM | "[URI:clienta@blahblah.com]" | sua::CSIPClientPublication::onSuccess
[09-04-06]17:50:52.614 | Debug | Contacts | "My Presence: Client publication succeeded. " | sua::CMyPresenceSink::OnSIPClientPublicationSuccess




I am not sure if its a Bria issue or OpenSIPS issue from the logs I am seeing. Why would OpenSIPS return a 404 Not Here?

I think I found the issue. My OpenSIPS config had this in it
if (is_method("SUBSCRIBE") && $rd == "blahblah.com") {

I saw that my Subscribe was not matching this condition, so I changed it to the following

if (is_method("SUBSCRIBE") ) {

And it looks to be working now. I am not sure why my first Subscribes would match this, but the subscribe to refresh my presene.winfo would not match.

weird....
Oh well.