Re: [OpenSER-Devel] db_mysql commands out of sync, presence

2008-03-31 Thread Juha Heinanen
Anca Vamanu writes:

 > It is strange that this error appears when a 'delete' is being executed. 
 > Not expected from the description of the error.
 > What version of libmysql-client are you using?

it is debian etch official version:

ii  libmysqlclient15off   5.0.32-7etch5   mysql database client library

-- juha

___
Devel mailing list
Devel@lists.openser.org
http://lists.openser.org/cgi-bin/mailman/listinfo/devel


Re: [OpenSER-Devel] db_mysql commands out of sync, presence

2008-03-31 Thread Henning Westerholt
On Monday 31 March 2008, Anca Vamanu wrote:
> hi,
>
> It is strange that this error appears when a 'delete' is being executed.
> Not expected from the description of the error.
> What version of libmysql-client are you using?

Hi,

process 11734 continues to process DB queries, the error seems only happens 
with PID 11733. It would be interesting what query this process has executed 
before this 'out of sync' problem appeared. Is this 'delete' triggered from a 
internal timer? Perhaps this could causes some sort of concurent DB access 
from the same process?

Cheers,

Henning

___
Devel mailing list
Devel@lists.openser.org
http://lists.openser.org/cgi-bin/mailman/listinfo/devel


Re: [OpenSER-Devel] db_mysql commands out of sync, presence

2008-03-31 Thread Anca Vamanu
hi,

It is strange that this error appears when a 'delete' is being executed. 
Not expected from the description of the error.
What version of libmysql-client are you using?

regards,
Anca

Juha Heinanen wrote:
> anca,
>
> this morning i noticed that during the night "out of sync" error had
> reappeared.  the first error was this:
>
> Mar 30 23:07:10 tutpro /usr/sbin/openser[11733]: 
> ERROR:db_mysql:db_mysql_submit_query: driver error on query: Commands out of 
> sync; you can't run this command now 
> Mar 30 23:07:10 tutpro /usr/sbin/openser[11733]: ERROR:core:db_do_delete: 
> error while submitting query 
> Mar 30 23:07:10 tutpro /usr/sbin/openser[11733]: ERROR:pua:db_update: while 
> deleting from db table pua 
>
> and after that it kept repeating itself until now.  i increased debug
> level and got the following around the error.  i don't know if it shows
> info by the new debug messages.
>
> -- juha
>
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_new_result: 
> allocate 28 bytes for result set at 0x81f1718 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: 5 columns returned from the query 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_allocate_columns: 
> allocate 20 bytes for result names at 0x81f0ee0 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_allocate_columns: 
> allocate 20 bytes for result types at 0x81f0ec0 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for RES_NAMES[0] at 
> 0x81f0b70 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81f0b70)[0]=[received] 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for RES_NAMES[1] at 
> 0x81f0b90 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81f0b90)[1]=[contact] 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for RES_NAMES[2] at 
> 0x81f0f20 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81f0f20)[2]=[socket] 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for RES_NAMES[3] at 
> 0x81f0f10 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81f0f10)[3]=[cflags] 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for RES_NAMES[4] at 
> 0x81f0f00 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
> DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81f0f00)[4]=[path] 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
> freeing 5 columns 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
> freeing RES_NAMES[0] at 0x81f0b70 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
> freeing RES_NAMES[1] at 0x81f0b90 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
> freeing RES_NAMES[2] at 0x81f0f20 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
> freeing RES_NAMES[3] at 0x81f0f10 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
> freeing RES_NAMES[4] at 0x81f0f00 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
> freeing result names at 0x81f0ee0 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
> freeing result types at 0x81f0ec0 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_rows: freeing 
> 0 rows 
> Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_result: 
> freeing result set at 0x81f1718 
> Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:pua:db_update: 
> NO_UPDATEDB_FLAG 
> Mar 31 07:47:47 test /usr/sbin/openser[11733]: 
> ERROR:db_mysql:db_mysql_submit_query: driver error on query: Commands out of 
> sync; you can't run this command now 
> Mar 31 07:47:47 test /usr/sbin/openser[11733]: ERROR:core:db_do_delete: error 
> while submitting query 
> Mar 31 07:47:47 test /usr/sbin/openser[11733]: ERROR:pua:db_update: while 
> deleting from db table pua 
> Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:pua:print_ua_pres: 
> ^Ipres_uri= sip:[EMAIL PROTECTED]   len= 20 
> Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:pua:print_ua_pres: ^Ietag= 
> a.1206800939.2338.1.10 - len= 22 
> Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:pua:print_ua_pres: ^Iid=  
> Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:pua:print_ua_pres: 
> ^Iexpires= 7704567 
> Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:presence:printf_subs:  
> ^I[pres_uri]= sip:[EMAIL PROTECTED] ^I[to_user]= foo.bar^I[to_domain]= 
> test.com ^I[w_user]= jh^I[w_domain]= test.com ^I[event]= presence ^I[status]= 
> active ^I[expires]= 1206942027 ^I[callid]= [EMAIL PROTECTED] ^I[to_

Re: [OpenSER-Devel] db_mysql commands out of sync, presence

2008-03-30 Thread Juha Heinanen
anca,

this morning i noticed that during the night "out of sync" error had
reappeared.  the first error was this:

Mar 30 23:07:10 tutpro /usr/sbin/openser[11733]: 
ERROR:db_mysql:db_mysql_submit_query: driver error on query: Commands out of 
sync; you can't run this command now 
Mar 30 23:07:10 tutpro /usr/sbin/openser[11733]: ERROR:core:db_do_delete: error 
while submitting query 
Mar 30 23:07:10 tutpro /usr/sbin/openser[11733]: ERROR:pua:db_update: while 
deleting from db table pua 

and after that it kept repeating itself until now.  i increased debug
level and got the following around the error.  i don't know if it shows
info by the new debug messages.

-- juha

Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_new_result: allocate 
28 bytes for result set at 0x81f1718 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: 5 columns returned from the query 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_allocate_columns: 
allocate 20 bytes for result names at 0x81f0ee0 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_allocate_columns: 
allocate 20 bytes for result types at 0x81f0ec0 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for RES_NAMES[0] at 
0x81f0b70 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81f0b70)[0]=[received] 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for RES_NAMES[1] at 
0x81f0b90 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81f0b90)[1]=[contact] 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for RES_NAMES[2] at 
0x81f0f20 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81f0f20)[2]=[socket] 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for RES_NAMES[3] at 
0x81f0f10 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81f0f10)[3]=[cflags] 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for RES_NAMES[4] at 
0x81f0f00 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: 
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x81f0f00)[4]=[path] 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
freeing 5 columns 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
freeing RES_NAMES[0] at 0x81f0b70 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
freeing RES_NAMES[1] at 0x81f0b90 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
freeing RES_NAMES[2] at 0x81f0f20 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
freeing RES_NAMES[3] at 0x81f0f10 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
freeing RES_NAMES[4] at 0x81f0f00 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
freeing result names at 0x81f0ee0 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_columns: 
freeing result types at 0x81f0ec0 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_rows: freeing 0 
rows 
Mar 31 07:47:46 test /usr/sbin/openser[11734]: DBG:core:db_free_result: freeing 
result set at 0x81f1718 
Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:pua:db_update: 
NO_UPDATEDB_FLAG 
Mar 31 07:47:47 test /usr/sbin/openser[11733]: 
ERROR:db_mysql:db_mysql_submit_query: driver error on query: Commands out of 
sync; you can't run this command now 
Mar 31 07:47:47 test /usr/sbin/openser[11733]: ERROR:core:db_do_delete: error 
while submitting query 
Mar 31 07:47:47 test /usr/sbin/openser[11733]: ERROR:pua:db_update: while 
deleting from db table pua 
Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:pua:print_ua_pres: 
^Ipres_uri= sip:[EMAIL PROTECTED]   len= 20 
Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:pua:print_ua_pres: ^Ietag= 
a.1206800939.2338.1.10 - len= 22 
Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:pua:print_ua_pres: ^Iid=  
Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:pua:print_ua_pres: 
^Iexpires= 7704567 
Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:presence:printf_subs:  
^I[pres_uri]= sip:[EMAIL PROTECTED] ^I[to_user]= foo.bar^I[to_domain]= test.com 
^I[w_user]= jh^I[w_domain]= test.com ^I[event]= presence ^I[status]= active 
^I[expires]= 1206942027 ^I[callid]= [EMAIL PROTECTED] ^I[to_tag]= 
25.11737.1206938427.10^I[from_tag]= rahuw ^I[contact]= sip:[EMAIL 
PROTECTED]:5066;transport=tcp^I[record_route]=  
Mar 31 07:47:47 test /usr/sbin/openser[11733]: DBG:presence:update_db_subs: 
INSERTDB_FLAG 
Mar 31 07:47:47 test /usr/sbin/openser[11733]: 
ERROR:db_mysql:db_mysql_submit_query: driver error on query: Commands out of 
sync; you can't run this command now 
Mar 31 07:4

Re: [OpenSER-Devel] db_mysql commands out of sync, presence

2008-03-30 Thread Juha Heinanen
anca,

i upgraded openser trunk from march 18 version to the latest one and
installed your debug patch.  after that i did all kinds of tests with
publish and other methods, restarted mysqld, etc., and was not anymore
able to reproduce the "commands out of sync" error.  i also tried using
both usrloc db_mode 1 and 3 and didn't get any errors.

so looks like something happened between march 18 and now that fixed the
problem.

-- juha

___
Devel mailing list
Devel@lists.openser.org
http://lists.openser.org/cgi-bin/mailman/listinfo/devel


Re: [OpenSER-Devel] db_mysql commands out of sync, presence

2008-03-28 Thread Anca Vamanu
There is something that I am aware of that could cause a similar problem 
if this parameter is set. And I will give a proper fix to it asap next week.
I did not succeeded to find the problem when the parameter is not set. 
Tried a couple of times last days to reproduce it , but with no success.
I will look again closer in the code and probably ask you, Juha, to help 
me with debugging messages.

regards,
Anca

Juha Heinanen wrote:
> Anca Vamanu writes:
>
>  > I will take a look.
>
> thanks.
>
>  > Juha, could you please help me and say if you have set the  
>  > enable_sphere_check presence module parameter in your configuration
>  > file?
>
> no, i have not set it.
>
> -- juha
>   


___
Devel mailing list
Devel@lists.openser.org
http://lists.openser.org/cgi-bin/mailman/listinfo/devel


Re: [OpenSER-Devel] db_mysql commands out of sync, presence

2008-03-28 Thread Juha Heinanen
Anca Vamanu writes:

 > I will take a look.

thanks.

 > Juha, could you please help me and say if you have set the  
 > enable_sphere_check presence module parameter in your configuration
 > file?

no, i have not set it.

-- juha

___
Devel mailing list
Devel@lists.openser.org
http://lists.openser.org/cgi-bin/mailman/listinfo/devel


Re: [OpenSER-Devel] db_mysql commands out of sync, presence

2008-03-28 Thread Anca Vamanu
Hi,

I will take a look.
Juha, could you please help me and say if you have set the  
enable_sphere_check presence module parameter in your configuration file? 

regards,
Anca

Henning Westerholt wrote:
> On Fri, March 28, 2008 2:14 pm, Juha Heinanen wrote:
>   
>> i'm getting these also in usrloc db_mode = 1:
>>
>> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]: LOG: Handling PUBLISH to
>> 
>> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]:
>> ERROR:db_mysql:db_mysql_submit_query: driver error on query: Commands out
>> of sync; you can't run this command now
>> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]: ERROR:core:db_do_query:
>> error while submitting query
>> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]:
>> ERROR:presence:update_presentity: unsuccessful sql query
>> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]:
>> ERROR:presence:handle_publish: when updating presentity
>> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]: ERROR: PUBLISH to
>>  failed
>>
>> i would really appreciate if db experts could help in solving this
>> problem.  what does Commands out of sync sync mean?  when does it
>> happen?
>> 
>
> Hi Juha,
>
> sorry for the late reply, caused from the VON and additional issues..
>
> This was discussed already some time ago:
> http://lists.openser.org/pipermail/devel/2008-February/012238.html
>
> Additional information is also present in the MySQL documentation:
> http://dev.mysql.com/doc/refman/5.1/en/commands-out-of-sync.html
>
>   
>> although in the above the errors resulted from publish, i have
>> seen the same happening also without any request processing as i have
>> reported earlier.  i have not changed anything in the way my openser is
>> running.  these errors just started to appear at some point this year
>> when i upgraded to a newer trunk.
>> 
>
> Anca commited a fix related to a bug in the presence code, that caused
> this problems. She also mentioned that an additional fix is necessary. I
> don't know if this is already fixed..
>
>   
>> if the cause for the errors cannot be found, perhaps it would would then
>> be better to go back to the working db implementation that existed at
>> the end of last year.
>> 
>
> I don't think that the error really is located in the db implementation.
> We've done quite a lot of work in the db interface and the additional
> modules that uses it, i don't think its a good idea to revert this all.
>
> I actually do some tests, but not at all for presence. Anybody else
> observed problems similar to this?
>
> Cheers,
>
> Henning
>
>
> ___
> Devel mailing list
> Devel@lists.openser.org
> http://lists.openser.org/cgi-bin/mailman/listinfo/devel
>
>   


___
Devel mailing list
Devel@lists.openser.org
http://lists.openser.org/cgi-bin/mailman/listinfo/devel


Re: [OpenSER-Devel] db_mysql commands out of sync, presence

2008-03-28 Thread Juha Heinanen
Henning Westerholt writes:

 > Anca commited a fix related to a bug in the presence code, that caused
 > this problems. She also mentioned that an additional fix is necessary. I
 > don't know if this is already fixed..

ok, i'll try with very latest trunk to see if it is still there.  i just
got the error when i had debug level 4 on.  so if acna has not yet fixed
the problem or does not know where it happens, the log may give some
hints.

-- juha

___
Devel mailing list
Devel@lists.openser.org
http://lists.openser.org/cgi-bin/mailman/listinfo/devel


Re: [OpenSER-Devel] db_mysql commands out of sync, presence

2008-03-28 Thread Henning Westerholt
On Fri, March 28, 2008 2:14 pm, Juha Heinanen wrote:
> i'm getting these also in usrloc db_mode = 1:
>
> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]: LOG: Handling PUBLISH to
> 
> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]:
> ERROR:db_mysql:db_mysql_submit_query: driver error on query: Commands out
> of sync; you can't run this command now
> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]: ERROR:core:db_do_query:
> error while submitting query
> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]:
> ERROR:presence:update_presentity: unsuccessful sql query
> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]:
> ERROR:presence:handle_publish: when updating presentity
> Mar 28 14:50:24 tutpro /usr/sbin/openser[11688]: ERROR: PUBLISH to
>  failed
>
> i would really appreciate if db experts could help in solving this
> problem.  what does Commands out of sync sync mean?  when does it
> happen?

Hi Juha,

sorry for the late reply, caused from the VON and additional issues..

This was discussed already some time ago:
http://lists.openser.org/pipermail/devel/2008-February/012238.html

Additional information is also present in the MySQL documentation:
http://dev.mysql.com/doc/refman/5.1/en/commands-out-of-sync.html

> although in the above the errors resulted from publish, i have
> seen the same happening also without any request processing as i have
> reported earlier.  i have not changed anything in the way my openser is
> running.  these errors just started to appear at some point this year
> when i upgraded to a newer trunk.

Anca commited a fix related to a bug in the presence code, that caused
this problems. She also mentioned that an additional fix is necessary. I
don't know if this is already fixed..

> if the cause for the errors cannot be found, perhaps it would would then
> be better to go back to the working db implementation that existed at
> the end of last year.

I don't think that the error really is located in the db implementation.
We've done quite a lot of work in the db interface and the additional
modules that uses it, i don't think its a good idea to revert this all.

I actually do some tests, but not at all for presence. Anybody else
observed problems similar to this?

Cheers,

Henning


___
Devel mailing list
Devel@lists.openser.org
http://lists.openser.org/cgi-bin/mailman/listinfo/devel