[sr-dev] [kamailio/kamailio] Presence not working with Postgresql && subs_db_mode = 3 && notifier_processes != 0 (#2739)

Thu May 20 12:58:24 CEST 2021

### Description

If I set notifier_processes = 0 then BLF (subscribe/notify) works as expected.

if I set notifier_processes to anything other than 0 then the initial subscribe works fine but when the device Re-Subscribes due to expiry of the timer I see errors in the kamailio log, the subsequent susbcribe fails and BLF no longer works. 

### Troubleshooting

#### Reproduction

This issue can be easily reproduced just by setting notifier_processes to 1.

#### Debugging Data

<!--
If you got a core dump, use gdb to extract troubleshooting data - full backtrace,
local variables and the list of the code at the issue location.

  gdb /path/to/kamailio /path/to/corefile
  bt full
  info locals
  list

If you are familiar with gdb, feel free to attach more of what you consider to
be relevant.
-->

```

```

#### Log Messages

```
ERROR: db_postgres [km_dbase.c:480]: db_postgres_query_lock(): transaction not in progress
ERROR: presence [subscribe.c:1708]: get_database_info(): querying subscription dialog
INFO: presence [subscribe.c:1129]: handle_subscribe(): getting stored info
```

#### SIP Traffic

<!--
If the issue is exposed by processing specific SIP messages, grab them with ngrep or save in a pcap file, then add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site).
-->

```
[11:28:02.095] TX to x.x.x.x:5060:
SUBSCRIBE sip:1005 at example.com;transport=udp SIP/2.0
Via: SIP/2.0/UDP y.y.y.y:51761;branch=z9hG4bK271d65c640 661e;rport
Contact: <sip:10004 at y.y.y.y:51761>
Max-Forwards: 70
Route: <sip:x.x.x.x;lr>
To: <sip:1005 at example.com;transport=udp>
From: <sip:10004 at example.com>;tag=602c0c864ab45075
Call-ID: 181910a72dc93418
CSeq: 26762 SUBSCRIBE
User-Agent: polycomVVX-VVX_400-UA/5.8.5.1256
Event: dialog
Accept: application/dialog-info+xml
Expires: 600
Supported:
Content-Length: 0

[11:28:02.184] RX from x.x.x.x:5060:
SIP/2.0 202 OK
Via: SIP/2.0/UDP y.y.y.y:51761;branch=z9hG4bK271d65c640 661e;rport=51761;received=y.y.y.y
To: <sip:1005 at example.com;transport=udp>;tag=f055057275da74fa400fb8f3e0bfdfcf-718a1cd7
From: <sip:10004 at example.com>;tag=602c0c864ab45075
Call-ID: 181910a72dc93418
CSeq: 26762 SUBSCRIBE
Expires: 600
Contact: <sip:x.x.x.x:5060;transport=udp>
Content-Length: 0

[11:28:02.1 ] RX from x.x.x.x:5060:
NOTIFY sip:10004 at y.y.y.y:51761 SIP/2.0
Record-Route: <sip:x.x.x.x;lr=on;ftag=f055057275da74fa400fb8f3e0bfdfcf-718a1cd7>
Via: SIP/2.0/UDP x.x.x.x;branch=z9hG4bK54.4071b642000000000000000000000000.0
To: <sip:10004 at example.com>;tag=602c0c864ab45075
From: <sip:1005 at example.com>;tag=f055057275da74fa400fb8f3e0bfdfcf-718a1cd7
CSeq: 1 NOTIFY
Call-ID: 181910a72dc93418
Content-Length: 266
Max-Forwards: 70
Event: dialog
Contact: <sip:x.x.x.x:5060;transport=udp>
Subscription-State: active;expires=600
Content-Type: application/dialog-info+xml

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="1" state="full" entity="sip:1005 at example.com">
  <dialog id="615293b33c62dec073e05d9421e9f48b" direction="recipient">	<state>terminated</state>	</dialog>
</dialog-info>

[11:28:02.1 ] TX to x.x.x.x:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP x.x.x.x;branch=z9hG4bK54.4071b642000000000000000000000000.0
To: <sip:10004 at example.com>;tag=602c0c864ab45075
From: <sip:1005 at example.com>;tag=f055057275da74fa400fb8f3e0bfdfcf-718a1cd7
CSeq: 1 NOTIFY
Call-ID: 181910a72dc93418
Server: polycomVVX-VVX_400-UA/5.8.5.1256
Content-Length: 0

...time...time...time...

[11:37:02.190] TX to x.x.x.x:5060:
SUBSCRIBE sip:x.x.x.x:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP y.y.y.y:51761;branch=z9hG4bK496e53396451225a;rport
Contact: <sip:10004 at y.y.y.y:51761>
Max-Forwards: 70
To: <sip:1005 at example.com;transport=udp>;tag=f055057275da74fa400fb8f3e0bfdfcf-718a1cd7
From: <sip:10004 at example.com>;tag=602c0c864ab45075
Call-ID: 181910a72dc93418
CSeq: 26763 SUBSCRIBE
User-Agent: polycomVVX-VVX_400-UA/5.8.5.1256
Event: dialog
Accept: application/dialog-info+xml
Expires: 600
Supported:
Content-Length: 0

[11:37:02.276] RX from x.x.x.x:5060:
SIP/2.0 500 Server Internal Error
Via: SIP/2.0/UDP y.y.y.y:51761;branch=z9hG4bK496e53396451225a;rport=51761;received=y.y.y.y
To: <sip:1005 at example.com;transport=udp>;tag=f055057275da74fa400fb8f3e0bfdfcf-718a1cd7
From: <sip:10004 at example.com>;tag=602c0c864ab45075
Call-ID: 181910a72dc93418
CSeq: 26763 SUBSCRIBE
Content-Length: 0
```

### Possible Solutions

<!--
If you found a solution or workaround for the issue, describe it. Ideally, provide a pull request with a fix.
-->

### Additional Information

  * **Kamailio Version** - output of `kamailio -v`

```
kamailio version: 5.5.0 (x86_64/linux) d4c1a1
postgres version: 12.7

```
Presence configuration:

```
modparam("presence_dialoginfo", "force_dummy_dialog", 1)
modparam("presence_dialoginfo", "force_single_dialog", 1)
modparam("presence_xml", "force_dummy_presence", 1)
modparam("presence_xml", "force_active", 1)
modparam("presence_xml", "disable_winfo", 1)
modparam("presence_xml", "disable_bla", 1)
modparam("presence", "subs_db_mode", 3)
modparam("presence", "expires_offset", 0)
modparam("presence", "send_fast_notify", 1)
modparam("presence", "clean_period", 0)
modparam("presence", "db_update_period", 0)
modparam("presence", "publ_cache", 0)
modparam("presence", "min_expires_action", 1)
modparam("presence", "min_expires", 300)
modparam("presence", "max_expires", 3600)
modparam("presence", "sip_uri_match", 1)
modparam("presence", "waitn_time", 1)
modparam("presence", "notifier_processes", 1)
modparam("presence", "db_url", "postgres://kamailio:***********@127.0.0.1/kamailio")
modparam("presence", "xavp_cfg", "pres")
modparam("presence", "local_log_level", 6)
modparam("presence", "startup_mode", 0)
modparam("presence", "force_delete", 1)
modparam("presence", "timeout_rm_subs", 0)
modparam("presence", "cseq_offset", 2)
```
db_postgres configuration:
All defaults just loading the module
```
loadmodule "db_postgres.so"
``` 
* **Operating System**:

<!--
Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04, CentOS 7.1, ...), MacOS, xBSD, Solaris, ...;
Kernel details (output of `uname -a`)
-->

```
Linux ********** 3.10.0-1062.4.3.el7.x86_64 #1 SMP Wed Nov 13 23:58:53 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

```

-- 
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2739
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20210520/c3ac8458/attachment.htm>