Re: [sr-dev] [SR-Users] db_mysql "Commands out of sync; you can't run this command now "
On Sunday 28 August 2011, MÉSZÁROS Mihály wrote:
I attached the log file. If you need detailed log/higher log level, then please let me know.
usrloc seems to be using the same connection from multiple processes:
pid: 18389 and 18391, connection: 0xb7387d5c
Aug 28 12:40:10 hal /usr/sbin/kamailio[18389]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 0xb7387d5c table: location query: select contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified from location where username='mutf-hd' order by q Aug 28 12:40:10 hal /usr/sbin/kamailio[18391]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 0xb7387d5c table: location query: select contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified from location where username='ppke-vjk' order by q Aug 28 12:40:10 hal /usr/sbin/kamailio[18389]: INFO: db_mysql [km_dbase.c:177]: store_result: con: 0xb7387d5c table: location Aug 28 12:40:10 hal /usr/sbin/kamailio[18389]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 0xb7387d5c table: location query: update location set expires='2011-08-28 12:45:10',q=-1.00 ,cseq=2,flags=0,cflags=0,user_agent='Polycom HDX 8000 HD (Release - 3.0.2.1-17007)',received=NULL,path=NULL,socket='tcp:195.111.192.7:5060',methods=24575,last_modified='2011-08-28 12:40:10' where username='mutf-hd' AND contact='sip:mutf-hd@193.225.216.28:5060;transport=tcp' AND callid='3533311123-1752' Aug 28 12:40:10 hal /usr/sbin/kamailio[18391]: INFO: db_mysql [km_dbase.c:177]: store_result: con: 0xb7387d5c table: location Aug 28 12:40:10 hal /usr/sbin/kamailio[18391]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 0xb7387d5c table: location query: insert into location Aug 28 12:40:10 hal /usr/sbin/kamailio[18389]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 0xb7387d5c table: location query: select contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified from location where username='de-tek-hpc' order by q Aug 28 12:40:10 hal /usr/sbin/kamailio[18389]: ERROR: db_mysql [km_dbase.c:131]: driver error on query: Commands out of sync; you can't run this command now
It probably needs a fix like below because mod_init has also created a db connection which is inherited by at least one child and ul_dbh is not 0 anymore. That process needs to be excluded from opening a database connection, all other childs need to open their own DB connection. I just don't know what rank mod_init is run as and thus don't know which process to exclude. Maybe some other dev can jump in.
diff --git a/modules_k/usrloc/ul_mod.c b/modules_k/usrloc/ul_mod.c index b3a9499..ca50b01 100644 --- a/modules_k/usrloc/ul_mod.c +++ b/modules_k/usrloc/ul_mod.c @@ -378,7 +378,7 @@ static int child_init(int _rank) break; }
- if (!ul_dbh) + if (rank != PROC_MAIN) ul_dbh = ul_dbf.init(&db_url); /* Get a new database connection */ if (!ul_dbh) { LM_ERR("child(%d): failed to connect to database\n", _rank);
Hi,
Your patch didn't work for me. The kamailio didn't start if i use "if ( _rank != PROC_MAIN)" So i commented out, both if statement, and now "out of sync problem disappeared"
--- a/modules_k/usrloc/ul_mod.c +++ b/modules_k/usrloc/ul_mod.c @@ -355,8 +355,11 @@ static int child_init(int _rank) break; }
- if (!ul_dbh) +LM_INFO("before misi ul_mod con: %p rank: %d",ul_dbh,_rank); +// if (!ul_dbh) +// if ( _rank != PROC_MAIN) ul_dbh = ul_dbf.init(&db_url); /* Get a new database connection */ +LM_INFO("after misi ul_mod con: %p rank: %d",ul_dbh,_rank); if (!ul_dbh) { LM_ERR("child(%d): failed to connect to database\n", _rank); return -1;
BUT
I am experiencing that in usrloc module, still more then one worker process share the same sql connection:
Aug 29 11:16:04 hal /usr/sbin/kamailio[21521]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: 1 Aug 29 11:16:04 hal /usr/sbin/kamailio[21523]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: 3 Aug 29 11:16:04 hal /usr/sbin/kamailio[21525]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: 5 Aug 29 11:16:04 hal /usr/sbin/kamailio[21521]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: 1 Aug 29 11:16:04 hal /usr/sbin/kamailio[21524]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: 4 Aug 29 11:16:04 hal /usr/sbin/kamailio[21527]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: 7 Aug 29 11:16:04 hal /usr/sbin/kamailio[21522]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: 2 Aug 29 11:16:04 hal /usr/sbin/kamailio[21526]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: 6 Aug 29 11:16:04 hal /usr/sbin/kamailio[21530]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: -1 Aug 29 11:16:04 hal /usr/sbin/kamailio[21508]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: 0 Aug 29 11:16:04 hal /usr/sbin/kamailio[21528]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: 8 Aug 29 11:16:04 hal /usr/sbin/kamailio[21523]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: 3 Aug 29 11:16:04 hal /usr/sbin/kamailio[21524]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: 4 Aug 29 11:16:04 hal /usr/sbin/kamailio[21525]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: 5 Aug 29 11:16:04 hal /usr/sbin/kamailio[21528]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: 8 Aug 29 11:16:04 hal /usr/sbin/kamailio[21522]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: 2 Aug 29 11:16:04 hal /usr/sbin/kamailio[21526]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: 6 Aug 29 11:16:04 hal /usr/sbin/kamailio[21529]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: (nil) rank: -1 Aug 29 11:16:04 hal /usr/sbin/kamailio[21527]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: 7 Aug 29 11:16:04 hal /usr/sbin/kamailio[21508]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: 0 Aug 29 11:16:04 hal /usr/sbin/kamailio[21530]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: -1 Aug 29 11:16:04 hal /usr/sbin/kamailio[21529]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb7286d5c rank: -1 Aug 29 11:16:04 hal /usr/sbin/kamailio[21536]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: 0xb7286d5c rank: 12 Aug 29 11:16:04 hal /usr/sbin/kamailio[21534]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: 0xb7286d5c rank: 10 Aug 29 11:16:04 hal /usr/sbin/kamailio[21533]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: 0xb7286d5c rank: 9 Aug 29 11:16:04 hal /usr/sbin/kamailio[21533]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb72ab174 rank: 9 Aug 29 11:16:04 hal /usr/sbin/kamailio[21535]: INFO: usrloc [ul_mod.c:358]: before misi ul_mod con: 0xb7286d5c rank: 11 Aug 29 11:16:04 hal /usr/sbin/kamailio[21534]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb72ab174 rank: 10 Aug 29 11:16:04 hal /usr/sbin/kamailio[21536]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb72ab174 rank: 12 Aug 29 11:16:04 hal /usr/sbin/kamailio[21535]: INFO: usrloc [ul_mod.c:363]: after misi ul_mod con: 0xb72ab174 rank: 11
Misi
2011-08-28 13:45 keltezéssel, Alex Hermann írta:
On Sunday 28 August 2011, MÉSZÁROS Mihály wrote:
I attached the log file. If you need detailed log/higher log level, then please let me know.
usrloc seems to be using the same connection from multiple processes:
pid: 18389 and 18391, connection: 0xb7387d5c
Aug 28 12:40:10 hal /usr/sbin/kamailio[18389]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 0xb7387d5c table: location query: select contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified from location where username='mutf-hd' order by q Aug 28 12:40:10 hal /usr/sbin/kamailio[18391]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 0xb7387d5c table: location query: select contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified from location where username='ppke-vjk' order by q Aug 28 12:40:10 hal /usr/sbin/kamailio[18389]: INFO: db_mysql [km_dbase.c:177]: store_result: con: 0xb7387d5c table: location Aug 28 12:40:10 hal /usr/sbin/kamailio[18389]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 0xb7387d5c table: location query: update location set expires='2011-08-28 12:45:10',q=-1.00 ,cseq=2,flags=0,cflags=0,user_agent='Polycom HDX 8000 HD (Release - 3.0.2.1-17007)',received=NULL,path=NULL,socket='tcp:195.111.192.7:5060',methods=24575,last_modified='2011-08-28 12:40:10' where username='mutf-hd' AND contact='sip:mutf-hd@193.225.216.28:5060;transport=tcp' AND callid='3533311123-1752' Aug 28 12:40:10 hal /usr/sbin/kamailio[18391]: INFO: db_mysql [km_dbase.c:177]: store_result: con: 0xb7387d5c table: location Aug 28 12:40:10 hal /usr/sbin/kamailio[18391]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 0xb7387d5c table: location query: insert into location Aug 28 12:40:10 hal /usr/sbin/kamailio[18389]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 0xb7387d5c table: location query: select contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified from location where username='de-tek-hpc' order by q Aug 28 12:40:10 hal /usr/sbin/kamailio[18389]: ERROR: db_mysql [km_dbase.c:131]: driver error on query: Commands out of sync; you can't run this command now
It probably needs a fix like below because mod_init has also created a db connection which is inherited by at least one child and ul_dbh is not 0 anymore. That process needs to be excluded from opening a database connection, all other childs need to open their own DB connection. I just don't know what rank mod_init is run as and thus don't know which process to exclude. Maybe some other dev can jump in.
diff --git a/modules_k/usrloc/ul_mod.c b/modules_k/usrloc/ul_mod.c index b3a9499..ca50b01 100644 --- a/modules_k/usrloc/ul_mod.c +++ b/modules_k/usrloc/ul_mod.c @@ -378,7 +378,7 @@ static int child_init(int _rank) break; }
if (!ul_dbh)
if (rank != PROC_MAIN) ul_dbh = ul_dbf.init(&db_url); /* Get a new database connection */ if (!ul_dbh) { LM_ERR("child(%d): failed to connect to database\n", _rank);
On Monday 29 August 2011, MÉSZÁROS Mihály wrote:
Your patch didn't work for me. The kamailio didn't start if i use "if ( _rank != PROC_MAIN)" So i commented out, both if statement, and now "out of sync problem disappeared"
That should do the trick, but it might be possible to create a zombie connection this way. I don't know how the initialization of modules works exactly, so I can't really help you with this.
BUT
I am experiencing that in usrloc module, still more then one worker process share the same sql connection:
That is weird. AFAIK, connections can't be shared between processes, there seems to be no locking/semaphores/whatever to protect against simultaneous access.
Maybe you got lucky in your tests and just didn't have enough traffic to hit the simultaneous access problem (yet).
I'm out of ideas here, sorry.
Hi,
Thank You Alex for your help!
Others? Daniel? Can You please help me?
Thanks, Misi
2011-08-29 13:09 keltezéssel, Alex Hermann írta:
On Monday 29 August 2011, MÉSZÁROS Mihály wrote:
Your patch didn't work for me. The kamailio didn't start if i use "if ( _rank != PROC_MAIN)" So i commented out, both if statement, and now "out of sync problem disappeared"
That should do the trick, but it might be possible to create a zombie connection this way. I don't know how the initialization of modules works exactly, so I can't really help you with this.
BUT
I am experiencing that in usrloc module, still more then one worker process share the same sql connection:
That is weird. AFAIK, connections can't be shared between processes, there seems to be no locking/semaphores/whatever to protect against simultaneous access.
Maybe you got lucky in your tests and just didn't have enough traffic to hit the simultaneous access problem (yet).
I'm out of ideas here, sorry.
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.
Hi,
I find the following:
grep "con: 17212"
Aug 29 17:05:27 hal /usr/sbin/kamailio[24001]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: insert into location (username,contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified ) values ('de-tek-hpc','sip:de-tek-hpc@193.6.138.201:5060;transport=tcp','2011-08-29 17:10:27',-1.00 ,'966616894-1736',2,0,0,'Polycom HDX 8000 HD (Release - 3.0.2.1-17007)',NULL,NULL,'tcp:195.111.192.7:5060',24575,'2011-08-29 17:05:27') Aug 29 17:05:27 hal /usr/sbin/kamailio[24001]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: delete from location where username='de-tek-hpc' Aug 29 17:05:30 hal /usr/sbin/kamailio[24002]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: select contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified from location where username='me-iit' order by q Aug 29 17:05:30 hal /usr/sbin/kamailio[24002]: INFO: db_mysql [km_dbase.c:175]: store_result: con: 17212 table: location Aug 29 17:05:30 hal /usr/sbin/kamailio[24002]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: update location set expires='2011-08-29 17:10:30',q=-1.00 ,cseq=3,flags=0,cflags=0,user_agent='Polycom HDX 8000 HD (Release - 3.0.2.1-17007)',received=NULL,path=NULL,socket='tcp:195.111.192.7:5060',methods=NULL,last_modified='2011-08-29 17:05:30' where username='me-iit' AND contact='sip:me-iit@193.6.5.220:5060;transport=tcp' AND callid='385875516-1729' Aug 29 17:05:37 hal /usr/sbin/kamailio[24003]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: select contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified from location where username='de-tek-hpc' order by q Aug 29 17:05:37 hal /usr/sbin/kamailio[24003]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: insert into location (username,contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified ) values ('de-tek-hpc','sip:de-tek-hpc@193.6.138.201:5060;transport=tcp','2011-08-29 17:10:37',-1.00 ,'976693266-1736',2,0,0,'Polycom HDX 8000 HD (Release - 3.0.2.1-17007)',NULL,NULL,'tcp:195.111.192.7:5060',24575,'2011-08-29 17:05:37') Aug 29 17:05:37 hal /usr/sbin/kamailio[24003]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: delete from location where username='de-tek-hpc' Aug 29 17:05:47 hal /usr/sbin/kamailio[24004]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: select contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified from location where username='de-tek-hpc' order by q Aug 29 17:05:47 hal /usr/sbin/kamailio[24004]: INFO: db_mysql [km_dbase.c:175]: store_result: con: 17212 table: location Aug 29 17:05:47 hal /usr/sbin/kamailio[24004]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: update location set expires='2011-08-29 17:10:47',q=-1.00 ,cseq=2,flags=0,cflags=0,user_agent='Polycom HDX 8000 HD (Release - 3.0.2.1-17007)',received=NULL,path=NULL,socket='tcp:195.111.192.7:5060',methods=24575,last_modified='2011-08-29 17:05:47' where username='de-tek-hpc' AND contact='sip:de-tek-hpc@193.6.138.201:5060;transport=tcp' AND callid='385871516-1736'
a full log piece:
Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: select c ontact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified from location where username='ppke-vjk' ord er by q Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: db_mysql [km_dbase.c:129]: driver error on query: Commands out of sync; you can't run this command now Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: <core> [db_query.c:103]: error while submitting query Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: usrloc [udomain.c:570]: db_query failed Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: insert i nto location (username,contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified ) values ('ppke-vjk ','sip:ppke-vjk@193.225.195.133:5061;transport=tls','2011-08-29 17:15:16',-1.00 ,'1254092986-1737',2,0,0,'Polycom HDX 8000 HD (Release - 3.0.2.1-17007)',NULL,NULL,'tls:195.111.192.7:5061',24575,'2011-08-29 17:10:16') Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: db_mysql [km_dbase.c:129]: driver error on query: Commands out of sync; you can't run this command now Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: <core> [db_query.c:186]: error while submitting query Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: usrloc [ucontact.c:513]: inserting contact in db failed Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: usrloc [urecord.c:474]: failed to insert in database Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: registrar [save.c:430]: failed to insert contact Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: INFO: db_mysql [km_dbase.c:83]: submit_query: con: 17212 table: location query: delete f rom location where username='ppke-vjk' Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: db_mysql [km_dbase.c:129]: driver error on query: Commands out of sync; you can't run this command now Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: <core> [db_query.c:242]: error while submitting query Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: usrloc [urecord.c:426]: failed to delete from database Aug 29 17:10:16 hal /usr/sbin/kamailio[24003]: ERROR: usrloc [udomain.c:896]: DB delete failed
Thanks, Misi
(I don't know may be matter, and i didn't mentioned yet, that i am running multiple kamaillio instance on different ip address but on the same machine.)
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.
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.
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 databaseconnection */
LM_INFO("misi after mysql: con: %ld rank: %d pid: %d\n",mysql_thread_id(((structmy_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.
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 databaseconnection */
LM_INFO("misi after mysql: con: %ld rank: %d pid: %d\n",mysql_thread_id(((structmy_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
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.
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 databaseconnection */
LM_INFO("misi after mysql: con: %ld rank: %d pid: %d\n",mysql_thread_id(((structmy_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
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 databaseconnection */
ul_dbh = ul_dbf.init(&db_url); /* Get a database connectionper 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 newdatabase connection */
LM_INFO("misi after mysql: con: %ld rank: %d pid: %d\n",mysql_thread_id(((structmy_con*)(ul_dbh->tail))->con),_rank,getpid());
if (!ul_dbh) { LM_ERR("child(%d): failed to connect todatabase\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
2011-08-31 12:18 keltezéssel, Daniel-Constantin Mierla írta:
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 databaseconnection */
ul_dbh = ul_dbf.init(&db_url); /* Get a database connectionper 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.
Thank You for clarification! I will compile it and get back to you with results.
Cheers, Misi
Hello Daniel,
Thank You, and many thanks to Alex too! The fix you made is working fine for me.
Cheers, Misi
Hello,
On 9/5/11 4:55 PM, MÉSZÁROS Mihály wrote:
Hello Daniel,
Thank You, and many thanks to Alex too! The fix you made is working fine for me.
thanks for testing.
Cheers, Daniel
-
Alex Hermann -
Daniel-Constantin Mierla -
MÉSZÁROS Mihály