<div dir="ltr">Ok so my findings so far:<div><br></div><div>1- db_mode=2 --> No errors.</div><div>2- db_mode=1 --> The reported error.</div><div><div>3- modparam("usrloc", "server_id_filter", 1) --> Irrelevant, errors happen with or without it on db_mode=1.</div><div><br></div><div>Anything else I can try in order to find out what is happening? My next step was to enable mysql logs or capture traffic and see what exactly is Kam sending...</div><div><br></div><div>Let me know your thoughts.</div><div><br></div><div>Thanks, </div><div>Joel.</div><div></div></div><div><br></div><div><br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Mon, Feb 24, 2020 at 11:26 AM Joel Serrano <<a href="mailto:joel@textplus.com">joel@textplus.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr">Hi Henning, <div><br></div><div><div>Every time I register, NodeA says OK, sends location by DMQ to NodeB, nodeB logs the error.</div><div></div></div><div><br></div><div>I tried moving the VIP from NodeA to NodeB, and the error stops happening on NodeA, and starts happening on NodeB.</div><div><br></div><div>I did not see this happening with db_mode=2, and I *think* it started happening when I enabled the server_id related params? I'm not 100% sure of this so I'm going to try some different combinations to see if I can narrow it down a little and provide more accurate details for you guys to find the issue.</div><div><br></div><div>I'll report back shortly...</div><div><br></div><div>Thanks! </div><div>Joel.</div><div><br></div><div><br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Mon, Feb 24, 2020 at 11:20 AM Henning Westerholt <<a href="mailto:hw@skalatan.de" target="_blank">hw@skalatan.de</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div lang="DE">
<div>
<p class="MsoNormal"><span>Hello Joel,<u></u><u></u></span></p>
<p class="MsoNormal"><span><u></u> <u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB">Feb 24 13:58:46 csbc02 csbc[9280]: ERROR: <core> [db.c:481]: db_use_table(): invalid parameter value<br>
Feb 24 13:58:46 csbc02 csbc[9280]: ERROR: usrloc [ucontact.c:670]: db_insert_ucontact(): sql use_table failed for: location<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB"><u></u> <u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB">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.<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB"><u></u> <u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB">Cheers,<u></u><u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB"><u></u> <u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB">Henning</span><span lang="EN-GB"><u></u><u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB"><u></u> <u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB">-- <u></u>
<u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB">Henning Westerholt –
</span><span><a href="https://skalatan.de/blog/" target="_blank"><span lang="EN-GB" style="color:rgb(5,99,193)">https://skalatan.de/blog/</span></a></span><span lang="EN-GB"><u></u><u></u></span></p>
<p class="MsoNormal"><span lang="EN-GB">Kamailio services –
</span><span><a href="https://gilawa.com/" target="_blank"><span lang="EN-GB" style="color:rgb(5,99,193)">https://gilawa.com</span></a></span><span>
<span lang="EN-GB"><u></u><u></u></span></span></p>
<p class="MsoNormal"><span lang="EN-GB"><u></u> <u></u></span></p>
<p class="MsoNormal" style="margin-left:35.4pt"><b>From:</b> sr-users <<a href="mailto:sr-users-bounces@lists.kamailio.org" target="_blank">sr-users-bounces@lists.kamailio.org</a>>
<b>On Behalf Of </b>Joel Serrano<br>
<b>Sent:</b> Monday, February 24, 2020 8:10 PM<br>
<b>To:</b> Daniel-Constantin Mierla <<a href="mailto:miconda@gmail.com" target="_blank">miconda@gmail.com</a>><br>
<b>Cc:</b> Kamailio (SER) - Users Mailing List <<a href="mailto:sr-users@lists.kamailio.org" target="_blank">sr-users@lists.kamailio.org</a>><br>
<b>Subject:</b> Re: [SR-Users] Database errors with usrloc db_mode=1 and dmq_usrloc<u></u><u></u></p>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">Hello Daniel, <u></u><u></u></p>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">I built from master and re-tested, debug log:<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">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<br>
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...<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:75]: add_contact(): aor: 1000107<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:76]: add_contact(): ci->ruid: uloc-2-5e507d6a-1bd5-3<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:77]: add_contact(): aorhash: 928379112<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:115]: add_contact(): '1000107' Not found in usrloc<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:117]: add_contact(): Insert record<br>
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<br>
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<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:826]: dmq_ul_cb_contact(): Contact received from DMQ... skip<br>
Feb 24 13:58:46 csbc02 csbc[9280]: ERROR: <core> [db.c:481]: db_use_table(): invalid parameter value<br>
Feb 24 13:58:46 csbc02 csbc[9280]: ERROR: usrloc [ucontact.c:670]: db_insert_ucontact(): sql use_table failed for: location<br>
Feb 24 13:58:46 csbc02 csbc[9280]: ERROR: usrloc [urecord.c:598]: insert_ucontact(): failed to insert in database<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:121]: add_contact(): Insert ucontact<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:124]: add_contact(): Release record<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: dmq_usrloc [usrloc_sync.c:126]: add_contact(): Unlock udomain<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: sl [sl.c:305]: send_reply(): reply in stateless mode (sl)<br>
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)<br>
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<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): SIP Reply (status):<br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: <core> [core/parser/msg_parser.c:622]: parse_msg(): version: <SIP/2.0><br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: <core> [core/parser/msg_parser.c:624]: parse_msg(): status: <200><br>
Feb 24 13:58:46 csbc02 csbc[9280]: DEBUG: <core> [core/parser/msg_parser.c:626]: parse_msg(): reason: <OK><u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">Thanks, <u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">Joel.<u></u><u></u></p>
</div>
</div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
<div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">On Mon, Feb 24, 2020 at 1:36 AM Daniel-Constantin Mierla <<a href="mailto:miconda@gmail.com" target="_blank">miconda@gmail.com</a>> wrote:<u></u><u></u></p>
</div>
<blockquote style="border-top:none;border-right:none;border-bottom:none;border-left:1pt solid rgb(204,204,204);padding:0cm 0cm 0cm 6pt;margin-left:4.8pt;margin-right:0cm">
<div>
<p style="margin-left:35.4pt">Hello,<u></u><u></u></p>
<p style="margin-left:35.4pt">the error message:<u></u><u></u></p>
<p style="margin-left:35.4pt">Feb 21 00:11:25 csbc02 csbc[13916]: ERROR: <core> [db.c:481]: db_use_table(): invalid parameter value<u></u><u></u></p>
<p style="margin-left:35.4pt">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?<u></u><u></u></p>
<p style="margin-left:35.4pt"> * <a href="https://github.com/kamailio/kamailio/commit/3843ae18599bfc1806ccb62df44bbc8ad41d60dd" target="_blank">
https://github.com/kamailio/kamailio/commit/3843ae18599bfc1806ccb62df44bbc8ad41d60dd</a><u></u><u></u></p>
<p style="margin-left:35.4pt">Cheers,<br>
Daniel<u></u><u></u></p>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">On 21.02.20 22:40, Joel Serrano wrote:<u></u><u></u></p>
</div>
<blockquote style="margin-top:5pt;margin-bottom:5pt">
<div>
<p class="MsoNormal" style="margin-left:35.4pt">Hello, <u></u><u></u></p>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">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.<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">The config we have is:<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"># ----- usrloc params -----<br>
modparam("usrloc", "db_url", DBURL)<br>
modparam("usrloc", "db_mode", 1)<br>
modparam("usrloc", "db_load", 0)<br>
modparam("usrloc", "db_insert_update", 1)<br>
modparam("usrloc", "db_timer_clean", 1)<br>
modparam("usrloc", "server_id_filter", 1)<br>
modparam("usrloc", "timer_procs", 2)<br>
modparam("usrloc", "timer_interval", 60)<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"># ----- dmq_usrloc params -----<br>
modparam("dmq_usrloc", "enable", 1)<br>
modparam("dmq_usrloc", "sync", 1)<br>
modparam("dmq_usrloc", "batch_msg_contacts", 50) # 50 contacts / message<br>
modparam("dmq_usrloc", "batch_size", 10000) # 10000 contacts / batch<br>
modparam("dmq_usrloc", "batch_usleep", 500000) # one batch every 500ms<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">With this setup, we assume:<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">1- almost real-time updated location info in the database.<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">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)<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">3- if both servers go down, locations are lost (as they will not reload from database on startup).<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">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):<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">Feb 21 00:11:25 csbc02 csbc[13916]: ERROR: <core> [db.c:481]: db_use_table(): invalid parameter value<br>
Feb 21 00:11:25 csbc02 csbc[13916]: ERROR: usrloc [ucontact.c:1136]: db_update_ucontact_ruid(): sql use_table failed<br>
Feb 21 00:11:25 csbc02 csbc[13916]: ERROR: usrloc [ucontact.c:1657]: update_contact_db(): failed to update database<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">I added debug logs to see if I could understand the reason:<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:478]: usrloc_dmq_handle_msg(): dmq message received from
<a href="http://sip:usrloc@10.2.1.181:5050" target="_blank">sip:usrloc@10.2.1.181:5050</a><br>
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...<br>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:75]: add_contact(): aor: 1063362<br>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:76]: add_contact(): ci->ruid: uloc-1-5e502cd3-5629-1<br>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:77]: add_contact(): aorhash: 928261667<br>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:115]: add_contact(): '1063362' Not found in usrloc<br>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:117]: add_contact(): Insert record<br>
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<br>
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<br>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:826]: dmq_ul_cb_contact(): Contact received from DMQ... skip<br>
Feb 21 14:38:34 csbc02 csbc[30796]: ERROR: <core> [db.c:481]: db_use_table(): invalid parameter value<br>
Feb 21 14:38:34 csbc02 csbc[30796]: ERROR: usrloc [ucontact.c:669]: db_insert_ucontact(): sql use_table failed<br>
Feb 21 14:38:34 csbc02 csbc[30796]: ERROR: usrloc [urecord.c:598]: insert_ucontact(): failed to insert in database<br>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:121]: add_contact(): Insert ucontact<br>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:124]: add_contact(): Release record<br>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: dmq_usrloc [usrloc_sync.c:126]: add_contact(): Unlock udomain<br>
Feb 21 14:38:34 csbc02 csbc[30796]: DEBUG: sl [sl.c:305]: send_reply(): reply in stateless mode (sl)<br>
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)<u></u><u></u></p>
</div>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">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?<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">Thanks, <u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt">Joel.<u></u><u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
</div>
</div>
<p class="MsoNormal" style="margin-left:35.4pt"><u></u> <u></u></p>
<pre style="margin-left:35.4pt">_______________________________________________<u></u><u></u></pre>
<pre style="margin-left:35.4pt">Kamailio (SER) - Users Mailing List<u></u><u></u></pre>
<pre style="margin-left:35.4pt"><a href="mailto:sr-users@lists.kamailio.org" target="_blank">sr-users@lists.kamailio.org</a><u></u><u></u></pre>
<pre style="margin-left:35.4pt"><a href="https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users" target="_blank">https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users</a><u></u><u></u></pre>
</blockquote>
<pre style="margin-left:35.4pt">-- <u></u><u></u></pre>
<pre style="margin-left:35.4pt">Daniel-Constantin Mierla -- <a href="http://www.asipto.com" target="_blank">www.asipto.com</a><u></u><u></u></pre>
<pre style="margin-left:35.4pt"><a href="http://www.twitter.com/miconda" target="_blank">www.twitter.com/miconda</a> -- <a href="http://www.linkedin.com/in/miconda" target="_blank">www.linkedin.com/in/miconda</a><u></u><u></u></pre>
<pre style="margin-left:35.4pt">Kamailio Advanced Training - March 9-11, 2020, Berlin - <a href="http://www.asipto.com" target="_blank">www.asipto.com</a><u></u><u></u></pre>
<pre style="margin-left:35.4pt">Kamailio World Conference - April 27-29, 2020, in Berlin -- <a href="http://www.kamailioworld.com" target="_blank">www.kamailioworld.com</a><u></u><u></u></pre>
</div>
</blockquote>
</div>
</div>
</div>
</blockquote></div>
</blockquote></div>