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


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

[11:28:02.095] TX to x.x.x.x:5060:
SUBSCRIBE sip:1005@example.com;transport=udp SIP/2.0
Via: SIP/2.0/UDP y.y.y.y:51761;branch=z9hG4bK271d65c640 661e;rport
Contact: <sip:10004@y.y.y.y:51761>
Max-Forwards: 70
Route: <sip:x.x.x.x;lr>
To: <sip:1005@example.com;transport=udp>
From: <sip:10004@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@example.com;transport=udp>;tag=f055057275da74fa400fb8f3e0bfdfcf-718a1cd7
From: <sip:10004@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@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@example.com>;tag=602c0c864ab45075
From: <sip:1005@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@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@example.com>;tag=602c0c864ab45075
From: <sip:1005@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@y.y.y.y:51761>
Max-Forwards: 70
To: <sip:1005@example.com;transport=udp>;tag=f055057275da74fa400fb8f3e0bfdfcf-718a1cd7
From: <sip:10004@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@example.com;transport=udp>;tag=f055057275da74fa400fb8f3e0bfdfcf-718a1cd7
From: <sip:10004@example.com>;tag=602c0c864ab45075
Call-ID: 181910a72dc93418
CSeq: 26763 SUBSCRIBE
Content-Length: 0

Possible Solutions

Additional Information

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"
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, view it on GitHub, or unsubscribe.