[SR-Users] Database errors with usrloc db_mode=1 and dmq_usrloc

Henning Westerholt hw at skalatan.de
Mon Feb 24 20:20:16 CET 2020 

Hello Joel,

Feb 24 13:58:46 csbc02 csbc[9280]: ERROR: <core> [db.c:481]: db_use_table(): invalid parameter value
Feb 24 13:58:46 csbc02 csbc[9280]: ERROR: usrloc [ucontact.c:670]: db_insert_ucontact(): sql use_table failed for: location

So the table name seems to be ok - this function also log this error if the DB connection handle is not initialized. But still the question why this happens.

Cheers,

Henning

--
Henning Westerholt – https://skalatan.de/blog/
Kamailio services – https://gilawa.com<https://gilawa.com/>

From: sr-users <sr-users-bounces at lists.kamailio.org> On Behalf Of Joel Serrano
Sent: Monday, February 24, 2020 8:10 PM
To: Daniel-Constantin Mierla <miconda at gmail.com>
Cc: Kamailio (SER) - Users Mailing List <sr-users at lists.kamailio.org>
Subject: Re: [SR-Users] Database errors with usrloc db_mode=1 and dmq_usrloc

Hello Daniel,

I built from master and re-tested, debug log:

Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: <core> [core/socket_info.c:635]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:423]: usrloc_dmq_execute_action(): Received DMQ_UPDATE. Update contact info...
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:75]: add_contact(): aor: 1000107
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:76]: add_contact(): ci->ruid: uloc-2-5e507d6a-1bd5-3
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:77]: add_contact(): aorhash: 928379112
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:115]: add_contact(): '1000107' Not found in usrloc
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:117]: add_contact(): Insert record
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: usrloc [ul_callback.h:83]: run_ul_callbacks(): contact=0x7f3a8cfdf170, callback type 1/15, id 0 entered
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:800]: dmq_ul_cb_contact(): Callback from usrloc with type=1
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:826]: dmq_ul_cb_contact(): Contact received from DMQ... skip
Feb 24 13:58:46 csbc02 csbc[9280]: ERROR: <core> [db.c:481]: db_use_table(): invalid parameter value
Feb 24 13:58:46 csbc02 csbc[9280]: ERROR: usrloc [ucontact.c:670]: db_insert_ucontact(): sql use_table failed for: location
Feb 24 13:58:46 csbc02 csbc[9280]: ERROR: usrloc [urecord.c:598]: insert_ucontact(): failed to insert in database
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:121]: add_contact(): Insert ucontact
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:124]: add_contact(): Release record
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:126]: add_contact(): Unlock udomain
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: sl [sl.c:305]: send_reply(): reply in stateless mode (sl)
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: <core> [core/msg_translator.c:161]: check_via_address(): (10.2.1.181, 10.2.1.181, 0)
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dialog [dlg_cseq.c:116]: dlg_cseq_prepare_new_msg(): prepare new msg for cseq update operations
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): SIP Reply  (status):
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: <core> [core/parser/msg_parser.c:622]: parse_msg():  version: <SIP/2.0>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: <core> [core/parser/msg_parser.c:624]: parse_msg():  status:  <200>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: <core> [core/parser/msg_parser.c:626]: parse_msg():  reason:  <OK>



Thanks,
Joel.

On Mon, Feb 24, 2020 at 1:36 AM Daniel-Constantin Mierla <miconda at gmail.com<mailto:miconda at gmail.com>> wrote:

Hello,

the error message:

Feb 21 00:11:25 csbc02 csbc[13916]: ERROR: <core> [db.c:481]: db_use_table(): invalid parameter value

Is printed if the database table name is not given as parameter (eg, null or empty). I pushed a patch to usrloc to print the table in the log message, can you try with latest master (or patch from next commit) and send again the log messages?

  * https://github.com/kamailio/kamailio/commit/3843ae18599bfc1806ccb62df44bbc8ad41d60dd

Cheers,
Daniel
On 21.02.20 22:40, Joel Serrano wrote:
Hello,

I have a setup with 2 kamailio in active/idle, locations are shared via dmq_usrloc, but database is also used as a cache where other systems can access and query "real-time" data.

The config we have is:

# ----- usrloc params -----
modparam("usrloc", "db_url", DBURL)
modparam("usrloc", "db_mode", 1)
modparam("usrloc", "db_load", 0)
modparam("usrloc", "db_insert_update", 1)
modparam("usrloc", "db_timer_clean", 1)
modparam("usrloc", "server_id_filter", 1)
modparam("usrloc", "timer_procs", 2)
modparam("usrloc", "timer_interval", 60)

# ----- dmq_usrloc params -----
modparam("dmq_usrloc", "enable", 1)
modparam("dmq_usrloc", "sync", 1)
modparam("dmq_usrloc", "batch_msg_contacts", 50)  # 50 contacts / message
modparam("dmq_usrloc", "batch_size", 10000)       # 10000 contacts / batch
modparam("dmq_usrloc", "batch_usleep", 500000)    # one batch every 500ms

With this setup, we assume:

1- almost real-time updated location info in the database.
2- as long as one of the two Kam is up, location information will not be lost (as they will sync with each other via DMQ)
3- if both servers go down, locations are lost (as they will not reload from database on startup).

Our tests work well with the above config, with one exception, on the idle node, we see a lot of (only happens on the node receiving location via dmq):

Feb 21 00:11:25 csbc02 csbc[13916]: ERROR: <core> [db.c:481]: db_use_table(): invalid parameter value
Feb 21 00:11:25 csbc02 csbc[13916]: ERROR: usrloc [ucontact.c:1136]: db_update_ucontact_ruid(): sql use_table failed
Feb 21 00:11:25 csbc02 csbc[13916]: ERROR: usrloc [ucontact.c:1657]: update_contact_db(): failed to update database

I added debug logs to see if I could understand the reason:

Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:478]: usrloc_dmq_handle_msg(): dmq message received from sip:usrloc at 10.2.1.181:5050<http://sip:usrloc@10.2.1.181:5050>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:423]: usrloc_dmq_execute_action(): Received DMQ_UPDATE. Update contact info...
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:75]: add_contact(): aor: 1063362
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:76]: add_contact(): ci->ruid: uloc-1-5e502cd3-5629-1
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:77]: add_contact(): aorhash: 928261667
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:115]: add_contact(): '1063362' Not found in usrloc
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:117]: add_contact(): Insert record
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: usrloc [ul_callback.h:83]: run_ul_callbacks(): contact=0x7fe41ff41f40, callback type 1/15, id 0 entered
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:800]: dmq_ul_cb_contact(): Callback from usrloc with type=1
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:826]: dmq_ul_cb_contact(): Contact received from DMQ... skip
Feb 21 14:38:34 csbc02 csbc[30796]: ERROR: <core> [db.c:481]: db_use_table(): invalid parameter value
Feb 21 14:38:34 csbc02 csbc[30796]: ERROR: usrloc [ucontact.c:669]: db_insert_ucontact(): sql use_table failed
Feb 21 14:38:34 csbc02 csbc[30796]: ERROR: usrloc [urecord.c:598]: insert_ucontact(): failed to insert in database
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:121]: add_contact(): Insert ucontact
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:124]: add_contact(): Release record
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:126]: add_contact(): Unlock udomain
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: sl [sl.c:305]: send_reply(): reply in stateless mode (sl)
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: <core> [core/msg_translator.c:161]: check_via_address(): (10.2.1.181, 10.2.1.181, 0)

Can anyone help me understand what's the problem? I have the server_id setting, and the modparam server_id_filter, so shouldn't the receiving node just ignore any database tasks?


Thanks,
Joel.





_______________________________________________

Kamailio (SER) - Users Mailing List

sr-users at lists.kamailio.org<mailto:sr-users at lists.kamailio.org>

https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

--

Daniel-Constantin Mierla -- www.asipto.com<http://www.asipto.com>

www.twitter.com/miconda<http://www.twitter.com/miconda> -- www.linkedin.com/in/miconda<http://www.linkedin.com/in/miconda>

Kamailio Advanced Training - March 9-11, 2020, Berlin - www.asipto.com<http://www.asipto.com>

Kamailio World Conference - April 27-29, 2020, in Berlin -- www.kamailioworld.com<http://www.kamailioworld.com>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20200224/89301fab/attachment.html>

More information about the sr-users mailing list