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

MÉSZÁROS Mihály misi at niif.hu
Wed Aug 31 10:49:54 CEST 2011


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 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 at lists.sip-router.org
>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>




More information about the sr-users mailing list