spine dies with Lost connection to MySQL server during query

[gandalf]

Are you able to monitor the number of mysql connections used during such a failure? Use the mysql statistics to do so. I recently had a very old FreeBSD that was suffering from a similar issue, but I did not see that for current OS's
R.

[chadd]

Are you able to monitor the number of mysql connections used during such a failure? Use the mysql statistics to do so. I recently had a very old FreeBSD that was suffering from a similar issue, but I did not see that for current OS's
R.

MAX CONNECTIONS
Current max_connections = 500
Current threads_connected = 61
Historic max_used_connections = 153
The number of used connections is 30% of the configured maximum.
Your max_connections variable seems to be fine.


Doesn't seem to be a connection issue.

[gandalf]

Well, due to performance reasons, we made that very SQL statement perform a multi-row insert. So it may happen, that the SQL created is to huge for your current mysql environment (this is an assumption).
To verify this, either a code change to reduce the size of tha SQL is required or a mysql setting has to be verified.
I'm not sitting at my dev box right now, so I can't name the exact places to look for.
R.

[chadd]

Well, due to performance reasons, we made that very SQL statement perform a multi-row insert. So it may happen, that the SQL created is to huge for your current mysql environment (this is an assumption).
To verify this, either a code change to reduce the size of tha SQL is required or a mysql setting has to be verified.
I'm not sitting at my dev box right now, so I can't name the exact places to look for.
R.

This what your looking for?


mysql> show variables like 'max_allowed_packet';
+--------------------+---------+
| Variable_name | Value |
+--------------------+---------+
| max_allowed_packet | 2097152 |
+--------------------+---------+
1 row in set (0.00 sec)

mysql>

What do you think?

[gandalf]

Well, in fact I'm just scanning the variables of mysql. The idea still is the same, but the correct option is a mystery to me (as I never came across that before). Some approaches:
- http://dev.mysql.com/doc/refman/5.5/en/ ... uffer_size
- http://dev.mysql.com/doc/refman/5.5/en/ ... wed_packet
R.

[MrRat]

Anyone had any luck resolving this issue. I cant seem to find a solution.

Code: Select all

# spine
SPINE: Using spine config file [/etc/spine.conf]
SPINE: Version 0.8.8a starting
11/21/2012 09:27:02 AM - SPINE: Poller[0] FATAL: MySQL Error:'2013', Message:'Lost connection to MySQL server during query' (Spine thread)

[MrRat]

I was just able to spend some more time working on this. The problem seems to be related to spine being built against MySQL-5.5 client libraries. I reverted mysql to 5.1.66 and recompiled spine against those libraries and the problem is solved. specifically libmysqlclient_r.so.16 instead of libmysqlclient_r.so.18 where this problem was occurring. I think that I can probably reinstall MySQL 5.5.x as long as I were to keep the .so.16 for my current spine binary and not rebuild spine against the so.18. I will try to test this next week.

[gandalf]

Please try attached patch when using latest libraries
R.

[chadd]

added the patch and I am watching the log. Will report by COB. Thanks,

-chadd.

[chadd]

added the patch and I am watching the log. Will report by COB. Thanks,

-chadd.

Problem does not appear to be resolved:

'),(448536,'errors_out','2012-12-03 09:50:19','0'),(448536,'discards_out','2012-12-03 09:50:19','0'),(448536,'discards_in','2012-12-03 09:50:19','0'),(448536,'errors_in','2012-12-03 09:50:19','0'),(448534,'errors_out','2012-12-03 09:50:19','0'),(448534,'discards_out','2012-12-03 09:50:19','0'),(448534,'discards_in','2012-12-03 09:50:19','0'),(448534,'errors_in','2012-12-03 09:50:19','0'),(448531,'errors_out','2012-12-03 09:50:19','0'),(448531,'discards_out','2012-12-03 09:50:19','0'),(448531,'discards_in','2012-12-03 09:50:19','0'),(448531,'errors_in','2012-12-03 09:50:19','0'),(448530,'errors_out','2012-12-03 09:50:19','0'),(448530,'discards_out','2012-12-03 09:50:19','0'),(448530,'discards_in','2012-12-03 09:50:19','0'),(448530,'errors_in','2012-12'12/03/2012 09:50:19 AM - SPINE: Poller[0] FATAL: MySQL Error:'2013', Message:'Lost connection to MySQL server during query' (Spine thread)
'),(448537,'fiveMin','2012-12-03 09:50:19','6
12/03/2012 09:50:19 AM - SPINE: Poller[0] ERROR: SQL Failed! Error:'2013', Message:'Lost connection to MySQL server during query', SQL Fragment:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (448539,'cisco_memused','2012-12-03 09:50:19','U'),(448538,'cisco_memfree','2012-12-03 09:50:19','U'),(448537,'oneMin','2012-12-03 09:50:19','6
12/03/2012 09:50:19 AM - SPINE: Poller[0] WARNING: SQL Failed! Error:'2006', Message:'MySQL server has gone away', Attempting to Reconnect
'),(451427,'errors_out','2012-12-03 09:50:19','0'),(451427,'discards_out','2012-12-03 09:50:19','0'),(451427,'discards_in','2012-12-03 09:50:19','0'),(451427,'errors_in','2012-12-03 09:50:19','0'),(451426,'errors_out','2012-12-03 09:50:19','0'),(451426,'discards_out','2012-12-03 09:50:19','0'),(451426,'discards_in','2012-12-03 09:50:19','0'),(451426,'errors_in','2012-12-03 09:50:19','0'),(451425,'errors_out','2012-12-03 09:50:19','0'),(451425,'discards_out','2012-12-03 09:50:19','0'),(451425,'discards_in','2012-12-03 09:50:19','0'),(451425,'errors_in','2012-12-03 09:50:19','0'),(451424,'errors_out','2012-12-03 09:50:19','0'),(451424,'discards_out','2012-12-03 09:50:19','0'),(451424,'discards_in','2012-12-03 09:50:19','0'),(451424,'erro'12/03/2012 09:50:19 AM - SPINE: Poller[0] WARNING: SQL Failed! Error:'2006', Message:'MySQL server has gone away', Attempting to Reconnect
'),(451428,'fiveMin','2012-12-03 09:50:19','6
'),(451337,'errors_out','2012-12-03 09:50:19','0'),(451337,'discards_out','2012-12-03 09:50:19','0'),(451337,'discards_in','2012-12-03 09:50:19','0'),(451337,'errors_in','2012-12-03 09:50:19','0'),(451336,'errors_out','2012-12-03 09:50:19','0'),(451336,'discards_out','2012-12-03 09:50:19','0'),(451336,'discards_in','2012-12-03 09:50:19','0'),(451336,'errors_in','2012-12-03 09:50:19','0'),(451335,'errors_out','2012-12-03 09:50:19','0'),(451335,'discards_out','2012-12-03 09:50:19','0'),(451335,'discards_in','2012-12-03 09:50:19','0'),(451335,'errors_in','2012-12-03 09:50:19','0'),(451334,'errors_out','2012-12-03 09:50:19','0'),(451334,'discards_out','2012-12-03 09:50:19','0'),(451334,'discards_in','2012-12-03 09:50:19','0'),(451334,'erro'12/03/2012 09:50:19 AM - SPINE: Poller[0] ERROR: SQL Failed! Error:'2013', Message:'Lost connection to MySQL server during query', SQL Fragment:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (451430,'cisco_memused','2012-12-03 09:50:19','25430272'),(451429,'cisco_memfree','2012-12-03 09:50:19','65056276'),(451428,'oneMin','2012-12-03 09:50:19','32
'),(451338,'fiveMin','2012-12-03 09:50:19','32
12/03/2012 09:50:19 AM - SPINE: Poller[0] ERROR: SQL Failed! Error:'2013', Message:'Lost connection to MySQL server during query', SQL Fragment:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (451340,'cisco_memused','2012-12-03 09:50:19','25481192'),(451339,'cisco_memfree','2012-12-03 09:50:19','65005356'),(451338,'oneMin','2012-12-03 09:50:19','4

-chadd.

[mar1usc]

I have the same problem on a machine that polls about 7k rrds.
With libmysqlclient_r.so.18.0.0 the whole process takes about 255 seconds and i only was able to run 1 thread.
If i increased the poller's threads i recieved the same error as the subject.

but.. after a read this thread and i rolled back to libmysqlclient_r.so.16.0.0 ONLY THIS FILE! (from a backup in march 2012) i am now able the increase the threads.

SO... thanks MrRat!

[cjwest]

I'd like to thank MrRat as well, after tweaking the mysql settings for a while (without any major progress) I came across this thread. Rather than downgrade the mysql libraries I recompiled cacti-spine against the current ones. I am no longer getting "POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting." errors or the errors that appeared to be the cause of that error:

SPINE: Poller[0] WARNING: SQL Failed! Error:'2006', Message:'MySQL server has gone away', Attempting to Reconnect
SPINE: Poller[0] FATAL: MySQL Error:'2013', Message:'Lost connection to MySQL server during query' (Spine thread)

[X505]

I'd like to thank MrRat as well, after tweaking the mysql settings for a while (without any major progress) I came across this thread. Rather than downgrade the mysql libraries I recompiled cacti-spine against the current ones. I am no longer getting "POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting." errors or the errors that appeared to be the cause of that error:

SPINE: Poller[0] WARNING: SQL Failed! Error:'2006', Message:'MySQL server has gone away', Attempting to Reconnect
SPINE: Poller[0] FATAL: MySQL Error:'2013', Message:'Lost connection to MySQL server during query' (Spine thread)

i tried that too but still get the same errors, could you give some details on how you compiled spine with libmysqlclient_r.so.16 please?

[chilek]

The same problem in my spine installation.
It has appeared after mysql upgrade from 5.1.70 to 5.5.39.
This is not apparently mysql server issue, because I've built spine
linked with libmysqlclient_r.so.16 (provided by mysql 5.1.70)
and it works fine with mysql server 5.5.39, but linked with libmysqlclient_r.so.18
(provided by mysql 5.5.39) doesn't.
Spine linked with older mysql client library displays message:
SPINE: Poller[0] WARNING: MySQL is NOT Thread Safe!
and linked with newer library version doesn't. It's quite strange, isn't it.

I suspect that is some kind of bug in interaction between mysql client library code
and posix threads code.

[chilek]

Looks like it is bug in libmysqlclient_r.so.18:
http://bugs.mysql.com/bug.php?id=65956
Process/thread should retry read() operation after interrupted previously
with error number EINTR.