Re: [SR-Users] db_mysql "Commands out of sync; you can't run this command now "

Wed, 31 Aug 2011 03:18:49 -0700 

Hello,

On 8/31/11 10:49 AM, MÉSZÁROS Mihály wrote:

Hi Daniel,

Thank You for your reply!

-       if (!ul_dbh)
- ul_dbh = ul_dbf.init(&db_url); /* Get a new database connection */ + ul_dbh = ul_dbf.init(&db_url); /* Get a database connection per child */
Are you sure that it will not cause any problem that rank -1 process in usrloc database will be initialized twice, and ul_dbh will be overloaded with new connection? 
I guess this will cause problem.
it is safe, we have connection pool system inside, allowing many modules to use the same db connection when the db url value is matched. So, if a connection with same db url exists, it will be reused. 

Cheers,
Daniel


You can see before:
Aug 29 22:34:12 hal /usr/sbin/kamailio[8299]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: -1 pid: 8299 Aug 29 22:34:12 hal /usr/sbin/kamailio[8300]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: -1 pid: 8300 Aug 29 22:34:12 hal /usr/sbin/kamailio[8299]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18552 rank: -1 pid: 8299 Aug 29 22:34:12 hal /usr/sbin/kamailio[8300]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18553 rank: -1 pid: 8300 

Thanks,
Misi

2011-08-31 09:43 keltezéssel, Daniel-Constantin Mierla írta:

Hello,
thanks for investigating further. I just committed a patch, pull the latest GIT and try again. Let me know if works ok. 

Thanks,
Daniel

On 8/30/11 9:58 AM, MÉSZÁROS Mihály wrote:
So the problem is that rank: 0 PROC_MAIN process initialitzed and have db connection with mod_child_init, and after rank 0 PROC_MAIN process is forking for tcp workers it contains the initialized ul_dbh and no unique connection created for the tcp workers. 

Any suggestion, solution?

Thanks,
Misi

2011-08-29 22:44 keltezéssel, MÉSZÁROS Mihály írta:

Hi,
With this debug i can see that all tcp connections are using the same db connection(18549). 
Any suggestion highly appreciated!
Please read collected information on the bottom of my email.

Misi

--- a/modules_k/usrloc/Makefile
+++ b/modules_k/usrloc/Makefile
@@ -8,12 +8,16 @@
 include ../../Makefile.defs
 auto_gen=
 NAME=usrloc.so
-LIBS=
+LIBS=-L/usr/lib/mysql -L/usr/lib -L/usr/lib/mysql -lmysqlclient -lz
+#LIBS=

 DEFS+=-DOPENSER_MOD_INTERFACE

+
 SERLIBPATH=../../lib
 SER_LIBS+=$(SERLIBPATH)/kmi/kmi
 SER_LIBS+=$(SERLIBPATH)/srdb1/srdb1
 SER_LIBS+=$(SERLIBPATH)/kcore/kcore
+
+
 include ../../Makefile.modules
diff --git a/modules_k/usrloc/ul_mod.c b/modules_k/usrloc/ul_mod.c
index c3fe26a..9ff1a4c 100644
--- a/modules_k/usrloc/ul_mod.c
+++ b/modules_k/usrloc/ul_mod.c
@@ -50,6 +50,10 @@
  * over a API. A main user of this API is the registrar module.
  * \see registrar
  */
+#include <sys/types.h>
+#include <unistd.h>
+#include <mysql/mysql.h>
+#include "../../modules/db_mysql/km_my_con.h"

 #include <stdio.h>
 #include "ul_mod.h"
@@ -355,8 +359,15 @@ static int child_init(int _rank)
                        break;
        }

+       LM_INFO("misi before mysql:   rank: %d  pid: %d\n",
+                               _rank,getpid());
+
        if (!ul_dbh)
ul_dbh = ul_dbf.init(&db_url); /* Get a new database connection */ 
+
+       LM_INFO("misi after mysql:  con: %ld  rank: %d  pid: %d\n",
+ mysql_thread_id(((struct my_con*)(ul_dbh->tail))->con),_rank,getpid()); 
+
        if (!ul_dbh) {
LM_ERR("child(%d): failed to connect to database\n", _rank); 
                return -1;
Aug 29 22:34:12 hal /usr/sbin/kamailio[8275]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 1 pid: 8275 Aug 29 22:34:12 hal /usr/sbin/kamailio[8275]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18543 rank: 1 pid: 8275 Aug 29 22:34:12 hal /usr/sbin/kamailio[8256]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 0 pid: 8256 Aug 29 22:34:12 hal /usr/sbin/kamailio[8294]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 5 pid: 8294 Aug 29 22:34:12 hal /usr/sbin/kamailio[8291]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 4 pid: 8291 Aug 29 22:34:12 hal /usr/sbin/kamailio[8288]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 3 pid: 8288 Aug 29 22:34:12 hal /usr/sbin/kamailio[8285]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 2 pid: 8285 Aug 29 22:34:12 hal /usr/sbin/kamailio[8298]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 8 pid: 8298 Aug 29 22:34:12 hal /usr/sbin/kamailio[8299]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: -1 pid: 8299 Aug 29 22:34:12 hal /usr/sbin/kamailio[8300]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: -1 pid: 8300 Aug 29 22:34:12 hal /usr/sbin/kamailio[8294]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18544 rank: 5 pid: 8294 Aug 29 22:34:12 hal /usr/sbin/kamailio[8296]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 6 pid: 8296 Aug 29 22:34:12 hal /usr/sbin/kamailio[8288]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18545 rank: 3 pid: 8288 Aug 29 22:34:12 hal /usr/sbin/kamailio[8297]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 7 pid: 8297 Aug 29 22:34:12 hal /usr/sbin/kamailio[8256]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18549 rank: 0 pid: 8256 Aug 29 22:34:12 hal /usr/sbin/kamailio[8298]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18548 rank: 8 pid: 8298 Aug 29 22:34:12 hal /usr/sbin/kamailio[8291]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18547 rank: 4 pid: 8291 Aug 29 22:34:12 hal /usr/sbin/kamailio[8285]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18546 rank: 2 pid: 8285 Aug 29 22:34:12 hal /usr/sbin/kamailio[8296]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18550 rank: 6 pid: 8296 Aug 29 22:34:12 hal /usr/sbin/kamailio[8299]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18552 rank: -1 pid: 8299 Aug 29 22:34:12 hal /usr/sbin/kamailio[8300]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18553 rank: -1 pid: 8300 Aug 29 22:34:12 hal /usr/sbin/kamailio[8297]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18554 rank: 7 pid: 8297 Aug 29 22:34:12 hal /usr/sbin/kamailio[8303]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 9 pid: 8303 Aug 29 22:34:12 hal /usr/sbin/kamailio[8304]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 10 pid: 8304 Aug 29 22:34:12 hal /usr/sbin/kamailio[8305]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 11 pid: 8305 Aug 29 22:34:12 hal /usr/sbin/kamailio[8303]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18549 rank: 9 pid: 8303 Aug 29 22:34:12 hal /usr/sbin/kamailio[8304]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18549 rank: 10 pid: 8304 Aug 29 22:34:12 hal /usr/sbin/kamailio[8305]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18549 rank: 11 pid: 8305 Aug 29 22:34:12 hal /usr/sbin/kamailio[8306]: INFO: usrloc [ul_mod.c:363]: misi before mysql: rank: 12 pid: 8306 Aug 29 22:34:12 hal /usr/sbin/kamailio[8306]: INFO: usrloc [ul_mod.c:369]: misi after mysql: con: 18549 rank: 12 pid: 8306 
hal:/home/misi# kamctl-vvc ps
database engine 'MYSQL' loaded
Control engine 'FIFO' loaded
entering fifo_cmd ps
Process::  ID=0 PID=8256 Type=attendant
Process:: ID=1 PID=8275 Type=udp receiver child=0 sock=195.111.192.7:5060 Process:: ID=2 PID=8285 Type=udp receiver child=1 sock=195.111.192.7:5060 Process:: ID=3 PID=8288 Type=udp receiver child=2 sock=195.111.192.7:5060 Process:: ID=4 PID=8291 Type=udp receiver child=3 sock=195.111.192.7:5060 Process:: ID=5 PID=8294 Type=udp receiver child=0 sock=[2001:738:0:404:0:0:0:7]:5060 Process:: ID=6 PID=8296 Type=udp receiver child=1 sock=[2001:738:0:404:0:0:0:7]:5060 Process:: ID=7 PID=8297 Type=udp receiver child=2 sock=[2001:738:0:404:0:0:0:7]:5060 Process:: ID=8 PID=8298 Type=udp receiver child=3 sock=[2001:738:0:404:0:0:0:7]:5060 
Process::  ID=9 PID=8299 Type=slow timer
Process::  ID=10 PID=8300 Type=timer
Process::  ID=11 PID=8301 Type=MI FIFO
Process::  ID=12 PID=8302 Type=ctl handler
Process::  ID=13 PID=8303 Type=tcp receiver child=0
Process::  ID=14 PID=8304 Type=tcp receiver child=1
Process::  ID=15 PID=8305 Type=tcp receiver child=2
Process::  ID=16 PID=8306 Type=tcp receiver child=3
Process::  ID=17 PID=8307 Type=tcp main process
FIFO command was:
:ps:openser_receiver_9501





2011-08-29 14:00 keltezéssel, Alex Hermann írta:

On Monday 29 August 2011, MÉSZÁROS Mihály wrote:

I am experiencing that in usrloc module, still more then one worker
process share the same sql connection:
I'm sorry, the first patch was totally bogus. Due to the forking of the childs, they have the same memory layout and a very high chance of allocating the same address (in their own address space) for the connection struct.
Attached patch should give a thread_id truly unique per connection. If you're able to find multiple processes using the same thread_id, you've found the 
cause.





_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users





_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users


--
Daniel-Constantin Mierla -- http://www.asipto.com
Kamailio Advanced Training, Oct 10-13, Berlin: http://asipto.com/u/kat
http://linkedin.com/in/miconda -- http://twitter.com/miconda


_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

Reply via email to