[OpenSIPS-Users] CRITICAL:db_mysql:db_mysql_do_prepared_query: too many mysql server reconnection failures

[Bogdan-Andrei Iancu]

Hi Aqs,

It looks like you have some sql connectivity problems. Are you sure your 
opensips can reach the mysql server ? all your errors (about long query 
time and about the failure to reconnect) do point to a connectivity 
problem to mysql server.

Regards,

Bogdan-Andrei Iancu
OpenSIPS Founder and Developer
http://www.opensips-solutions.com

On 26.01.2016 00:27, Aqs Younas wrote:
> Hi.
>
> I am load testing my opensips(2.1.2) with sipp on. As soon as I send 
> calls with 50 cps i see this in logs.
>
> Jan 25 21:00:05 66-226-76-150 ./opensips[16398]: 
> INFO:db_mysql:switch_state_to_disconnected: disconnect event for 
> 0x7f17b530f338
> Jan 25 21:00:05 66-226-76-150 ./opensips[16398]: 
> INFO:db_mysql:reset_all_statements: reseting all statements on 
> connection: (0x7f17b530f1a0) 0x7f17b530f338
> Jan 25 21:00:05 66-226-76-150 ./opensips[16400]: 
> WARNING:db_mysql:log_expiry: threshold exceeded : mysql prep stmt took 
> too long - 1999302 us.Source : delete from dialo
> g where dlg_id=?
> Jan 25 21:00:05 66-226-76-150 ./opensips[16400]: 
> INFO:db_mysql:switch_state_to_disconnected: disconnect event for 
> 0x7f17b530f338
> Jan 25 21:00:05 66-226-76-150 ./opensips[16400]: 
> INFO:db_mysql:reset_all_statements: reseting all statements on 
> connection: (0x7f17b530f1a0) 0x7f17b530f338
> Jan 25 21:00:05 66-226-76-150 ./opensips[16398]: 
> INFO:db_mysql:connect_with_retry: re-connected successful for 
> 0x7f17b530f338
> Jan 25 21:00:05 66-226-76-150 ./opensips[16400]: 
> INFO:db_mysql:connect_with_retry: re-connected successful for 
> 0x7f17b530f338
> Jan 25 21:00:05 66-226-76-150 ./opensips[16398]: 
> INFO:db_mysql:db_mysql_do_prepared_query: reconnected to mysql server 
> -> re-init the statement
> Jan 25 21:00:05 66-226-76-150 ./opensips[16400]: 
> INFO:db_mysql:db_mysql_do_prepared_query: reconnected to mysql server 
> -> re-init the statement
> Jan 25 21:00:05 66-226-76-150 ./opensips[16398]: 
> CRITICAL:db_mysql:db_mysql_do_prepared_query: too many mysql server 
> reconnection failures
> Jan 25 21:00:05 66-226-76-150 ./opensips[16398]: 
> ERROR:dialog:update_dialog_dbinfo: could not update database info
> Jan 25 21:00:05 66-226-76-150 ./opensips[16400]: 
> CRITICAL:db_mysql:db_mysql_do_prepared_query: too many mysql server 
> reconnection failures
> Jan 25 21:00:05 66-226-76-150 ./opensips[16400]: 
> ERROR:dialog:update_dialog_dbinfo: could not add another dialog to db
> Jan 25 21:00:05 66-226-76-150 ./opensips[16398]: 
> WARNING:core:handle_timer_job: timer job <dlg-timer> has a 2310000 us 
> delay in execution
> Jan 25 21:00:05 66-226-76-150 ./opensips[16398]: 
> WARNING:core:handle_timer_job: timer job <blcore-expire> has a 2310000 
> us delay in execution
> Jan 25 21:00:05 66-226-76-150 ./opensips[16396]: 
> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 80000 us 
> delay in execution
> Jan 25 21:00:05 66-226-76-150 ./opensips[16400]: 
> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 80000 us 
> delay in execution
> Jan 25 21:00:05 66-226-76-150 ./opensips[16390]: 
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already schedualed 
> for 1436630 ms (now 1436730 ms), it may overlap.
> .
> Jan 25 21:00:05 66-226-76-150 ./opensips[16390]: 
> WARNING:core:utimer_ticker: utimer task <tm-utimer> already schedualed 
> for 1436730 ms (now 1436830 ms), it may overlap.
> .
> Jan 25 21:00:05 66-226-76-150 ./opensips[16395]: 
> WARNING:db_mysql:log_expiry: threshold exceeded : mysql prep stmt took 
> too long - 1999067 us.Source : delete from dialo
> g where dlg_id=?
> Jan 25 21:00:05 66-226-76-150 ./opensips[16395]: 
> INFO:db_mysql:switch_state_to_disconnected: disconnect event for 
> 0x7f17b530f338
> Jan 25 21:00:05 66-226-76-150 ./opensips[16395]: 
> INFO:db_mysql:reset_all_statements: reseting all statements on 
> connection: (0x7f17b530f1a0) 0x7f17b530f338
> Jan 25 21:00:05 66-226-76-150 ./opensips[16395]: 
> INFO:db_mysql:connect_with_retry: re-connected successful for 
> 0x7f17b530f338
> Jan 25 21:00:05 66-226-76-150 ./opensips[16395]: 
> INFO:db_mysql:db_mysql_do_prepared_query: reconnected to mysql server 
> -> re-init the statement
> Jan 25 21:00:05 66-226-76-150 ./opensips[16395]: 
> CRITICAL:db_mysql:db_mysql_do_prepared_query: too many mysql server 
> reconnection failures
> Jan 25 21:00:05 66-226-76-150 ./opensips[16395]: 
> ERROR:dialog:update_dialog_dbinfo: could not add another dialog to db
> Jan 25 21:00:05 66-226-76-150 ./opensips[16395]: 
> WARNING:core:handle_timer_job: utimer job <tm-utimer> has a 50000 us 
> delay in execution
>
> mysql server is on localhost and server is of good specs.
>
> Could someone help me how i resolve or why there are so many these lines.
>
> Thanks.
> <https://www.avast.com/sig-email?utm_medium=email&utm_source=link&utm_campaign=sig-email&utm_content=webmail> 
> 	This email has been sent from a virus-free computer protected by Avast.
> www.avast.com 
> <https://www.avast.com/sig-email?utm_medium=email&utm_source=link&utm_campaign=sig-email&utm_content=webmail> 
>
>
>
>
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20160126/4c6e7155/attachment-0001.htm>