Your suspect was correct: I was able to reproduce exactly the same errors simply by stopping a restarting the MySQL server (thus breaking old connections).

OpenSER is using MySQL library version 5.0.18. The MySQL server is version 4.0.27.

Bye.

Bogdan-Andrei Iancu wrote:

Hi Federico,

please check if when you get this errors your openser process is still connected to the mysql server. the interesting part is that no error string is present into the log: OpenSER[19895]: submit_query:

regards, bogdan

Federico Giannici wrote:

...

We recently upgraded from version 1.0.0 to 1.1.0 from CVS of a few days ago.

After a couple of days of uptime, some SQL errors began to appear. First there was this one:

Aug 21 10:07:07 eowyn OpenSER[19895]: ERROR: warning_builder: buffer size exceeded Aug 21 10:07:07 eowyn OpenSER[19895]: WARNING: warning skipped -- too big Aug 21 10:07:07 eowyn OpenSER[19895]: submit_query: Aug 21 10:07:07 eowyn OpenSER[19895]: db_insert: Error while submitting query Aug 21 10:07:07 eowyn OpenSER[19895]: ERROR:acc:acc_db_request: Error while inserting to database

Then, some errors like this:

Aug 21 15:41:28 eowyn OpenSER[19895]: submit_query: Aug 21 15:41:28 eowyn OpenSER[19895]: db_insert: Error while submitting query Aug 21 15:41:28 eowyn OpenSER[19895]: ERROR:acc:acc_db_request: Error while inserting to database

Or the following:

Aug 21 19:02:10 eowyn OpenSER[20604]: submit_query: Aug 21 19:02:10 eowyn OpenSER[20604]: db_query: Error while submitting query Aug 21 19:02:10 eowyn OpenSER[20604]: NM ERROR: nm_hash_load_domains(): error with dbf.query()

The nm_hash_load_domains() function is a module of mine, that make an SQL query. No problem with version 1.0.0.

Is there any SQL known problem in the 1.1.0 CVS version? Maybe the first error caused some memory garbage?

Thanks.

Federico Giannici wrote:

Bogdan-Andrei Iancu wrote:

...

Federico please apply the attached patch and send me the output.

OK, here it is:

Aug 22 15:50:34 eowyn OpenSER[16778]: submit_query: errno code is 2013

this is CR_SERVER_LOST

Aug 22 15:50:34 eowyn OpenSER[16778]: submit_query: errno code is 0

this means no error :-/

Aug 22 15:50:34 eowyn OpenSER[16778]: submit_query: Aug 22 15:50:34 eowyn OpenSER[16778]: db_query: Error while submitting query

can you check on the mysql server if the query was performed or not? because the strange part is that submit_query returns a non zero value but the mysql_error reports no error...

regards, bogdan

Any news on this problem?

Today I found that the problem occurs even when MySQL is NOT restarted. Here it is example of a query that seems to fail but without an error code (no previous error 2013):

Aug 23 16:36:58 eowyn OpenSER[28950]: submit_query: errno code is 0 Aug 23 16:36:58 eowyn OpenSER[28950]: submit_query: Aug 23 16:36:58 eowyn OpenSER[28950]: db_query: Error while submitting query

As said before, a new connection is done to the MySQL server, but no query is executed and the connection is immediately closed (instead of keeping it open).

Bye.

Federico Giannici wrote:

Bogdan-Andrei Iancu wrote:

...

Federico Giannici wrote:

...

Aug 22 15:50:34 eowyn OpenSER[16778]: submit_query: Aug 22 15:50:34 eowyn OpenSER[16778]: db_query: Error while submitting query

can you check on the mysql server if the query was performed or not? because the strange part is that submit_query returns a non zero value but the mysql_error reports no error...

After the SQL server is restarted then every time a query is done by OpenSER a new connection is opened (and then closed) ma the query is NOT executed.

Here it is an example:

26 Connect ser@eowyn.neomedia.it on ser 26 Query SET NAMES latin1 26 Quit

Bye.

Further reading the MySQL documentation, I found that:

"Prior to MySQL 5.0.19 [or 5.1.8], even if the reconnect flag in the MYSQL structure is equal to 1, MySQL does not automatically reconnect and re-issue the query as it doesn't know if the server did get the original query or not."

And I was using just version 5.0.18!

Now I upgraded to version 5.0.22 and the problem now seems to be resolved.

Bye.

Federico Giannici wrote:

I have found that now the correct way to set the reconnection in MySQL is to use the mysql_options() function. Here it is the description of the MYSQL_OPT_RECONNECT option: "Enable or disable automatic reconnection to the server if the connection is found to have been lost. Reconnect has been off by default since MySQL 5.0.3; this option is new in 5.0.13 and provides a way to set reconnection behavior explicitly.".

So I replaced the "ptr->con->reconnect = 1;" instruction in "mysql/my_con.c" with the following lines BEFORE the call to mysql_real_connect():

my_bool reconnect; reconnect=1; mysql_options(ptr->con,MYSQL_OPT_RECONNECT,(char*)&reconnect);

Well, it continues to DON'T work, but the behavior changed: it no longer fails with error 0 (?). Now it fails with error 2013 and then 2006:

Aug 26 17:38:53 eowyn OpenSER[10042]: submit_query: errno code is 2013 Aug 26 17:38:53 eowyn OpenSER[10042]: submit_query: errno code is 2006 Aug 26 17:38:53 eowyn OpenSER[10042]: submit_query: errno code is 2006 Aug 26 17:38:53 eowyn OpenSER[10042]: submit_query: MySQL server has gone away Aug 26 17:38:53 eowyn OpenSER[10042]: db_insert: Error while submitting query Aug 26 17:38:53 eowyn OpenSER[10042]: db_insert_ucontact(): Error while inserting contact Aug 26 17:38:53 eowyn OpenSER[10042]: ERROR:usrloc:insert_ucontact: failed to insert in database

Moreover, this time NO connection to the MySQL is actually done (previously a connection was done, but without any query).

In conclusion, it appears to me that the reconnections under MySQL are a great mess, and they probably depend on the actual version of client and server used.

So, I suggest to don't depend on them. On the submit_query() function, after the 3 attempts, if the error is still CR_SERVER_GONE_ERROR or CR_SERVER_LOST, we should close the connection and try to reopen it.

What do you think?

Bye.

Federico Giannici wrote:

...

Any news on this problem?

Today I found that the problem occurs even when MySQL is NOT restarted. Here it is example of a query that seems to fail but without an error code (no previous error 2013):

Aug 23 16:36:58 eowyn OpenSER[28950]: submit_query: errno code is 0 Aug 23 16:36:58 eowyn OpenSER[28950]: submit_query: Aug 23 16:36:58 eowyn OpenSER[28950]: db_query: Error while submitting query

As said before, a new connection is done to the MySQL server, but no query is executed and the connection is immediately closed (instead of keeping it open).

Bye.

Federico Giannici wrote:

...

Bogdan-Andrei Iancu wrote:

...

Federico Giannici wrote:

...

Aug 22 15:50:34 eowyn OpenSER[16778]: submit_query: Aug 22 15:50:34 eowyn OpenSER[16778]: db_query: Error while submitting query

can you check on the mysql server if the query was performed or not? because the strange part is that submit_query returns a non zero value but the mysql_error reports no error...

After the SQL server is restarted then every time a query is done by OpenSER a new connection is opened (and then closed) ma the query is NOT executed.

Here it is an example:

26 Connect ser@eowyn.neomedia.it on ser 26 Query SET NAMES latin1 26 Quit

Bye.

Klaus Darilion wrote:

Hi Federico!

Can you please make a patch and submit it at the bug tracker on sourceforge?

I don't know enough of the internals of the OpenSER sql connections handling to implement it.

Moreover, as I said earlier, I solved the problem upgranding the MySQL client library to a newer version.

Maybe, it could be useful to write somewhere that automatic reconnections under MySQL work only with version >= 5.0.19 or 5.1.8.

Bye.

Federico Giannici wrote:

...

I have found that now the correct way to set the reconnection in MySQL is to use the mysql_options() function. Here it is the description of the MYSQL_OPT_RECONNECT option: "Enable or disable automatic reconnection to the server if the connection is found to have been lost. Reconnect has been off by default since MySQL 5.0.3; this option is new in 5.0.13 and provides a way to set reconnection behavior explicitly.".

So I replaced the "ptr->con->reconnect = 1;" instruction in "mysql/my_con.c" with the following lines BEFORE the call to mysql_real_connect():

my_bool reconnect; reconnect=1; mysql_options(ptr->con,MYSQL_OPT_RECONNECT,(char*)&reconnect);

Well, it continues to DON'T work, but the behavior changed: it no longer fails with error 0 (?). Now it fails with error 2013 and then 2006:

Aug 26 17:38:53 eowyn OpenSER[10042]: submit_query: errno code is 2013 Aug 26 17:38:53 eowyn OpenSER[10042]: submit_query: errno code is 2006 Aug 26 17:38:53 eowyn OpenSER[10042]: submit_query: errno code is 2006 Aug 26 17:38:53 eowyn OpenSER[10042]: submit_query: MySQL server has gone away Aug 26 17:38:53 eowyn OpenSER[10042]: db_insert: Error while submitting query Aug 26 17:38:53 eowyn OpenSER[10042]: db_insert_ucontact(): Error while inserting contact Aug 26 17:38:53 eowyn OpenSER[10042]: ERROR:usrloc:insert_ucontact: failed to insert in database

Moreover, this time NO connection to the MySQL is actually done (previously a connection was done, but without any query).

In conclusion, it appears to me that the reconnections under MySQL are a great mess, and they probably depend on the actual version of client and server used.

So, I suggest to don't depend on them. On the submit_query() function, after the 3 attempts, if the error is still CR_SERVER_GONE_ERROR or CR_SERVER_LOST, we should close the connection and try to reopen it.

What do you think?

Bye.

Federico Giannici wrote:

...

Any news on this problem?

Today I found that the problem occurs even when MySQL is NOT restarted. Here it is example of a query that seems to fail but without an error code (no previous error 2013):

Aug 23 16:36:58 eowyn OpenSER[28950]: submit_query: errno code is 0 Aug 23 16:36:58 eowyn OpenSER[28950]: submit_query: Aug 23 16:36:58 eowyn OpenSER[28950]: db_query: Error while submitting query

As said before, a new connection is done to the MySQL server, but no query is executed and the connection is immediately closed (instead of keeping it open).

Bye.

Federico Giannici wrote:

...

Bogdan-Andrei Iancu wrote:

...

Federico Giannici wrote:

...

Aug 22 15:50:34 eowyn OpenSER[16778]: submit_query: Aug 22 15:50:34 eowyn OpenSER[16778]: db_query: Error while submitting query

can you check on the mysql server if the query was performed or not? because the strange part is that submit_query returns a non zero value but the mysql_error reports no error...

After the SQL server is restarted then every time a query is done by OpenSER a new connection is opened (and then closed) ma the query is NOT executed.

Here it is an example:

26 Connect ser@eowyn.neomedia.it on ser 26 Query SET NAMES latin1 26 Quit

Bye.