Spine trouble?

ame · Post by **ame** » Wed Jan 23, 2008 10:17 pm

Hi,

I have got fresh installation of cacti and spine (both .87a) under debian etch plus the plugin architecture 1.4 installed (but no plugin installed in the moment). For testing I have added 10-15 devices. So after lately 30 minutes the poller rans into problems:

01/24/2008 03:52:01 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:52:01 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:52:01 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:52:01 AM - SPINE: Poller[0] FATAL: Connection Failed: Too many connections (Spine thread)
01/24/2008 03:52:01 AM - SPINE: Poller[0] ERROR: SS[999] Script Server did not start properly return message was: 'FATAL: Cannot connect to MySQL server on 'localhost'. Please make sure you have specified a valid MySQL database name in 'include/config.php''
01/24/2008 03:52:00 AM - SYSTEM STATS: Time:0.1231 Method:spine Processes:1 Threads:4 Hosts:14 HostsPerProcess:14 DataSources:841 RRDsProcessed:0
01/24/2008 03:52:00 AM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting.
01/24/2008 03:51:42 AM - AUTH LOGIN: User 'admin' Authenticated
01/24/2008 03:51:00 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:51:00 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:51:00 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:51:00 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:51:00 AM - SPINE: Poller[0] FATAL: Connection Failed: Too many connections (Spine thread)
01/24/2008 03:51:00 AM - SYSTEM STATS: Time:0.1230 Method:spine Processes:1 Threads:4 Hosts:14 HostsPerProcess:14 DataSources:841 RRDsProcessed:0
01/24/2008 03:51:00 AM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting.
01/24/2008 03:50:02 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:50:02 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:50:02 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:50:02 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:50:02 AM - SPINE: Poller[0] FATAL: Connection Failed: Too many connections (Spine thread)
01/24/2008 03:50:01 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:50:01 AM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Potential Data Source Issues for Data Sources: users(DS[6])
01/24/2008 03:50:00 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:50:00 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:50:00 AM - PHPSVR: Poller[0] ERROR: Input Expected, Script Server Terminating
01/24/2008 03:50:00 AM - SPINE: Poller[0] FATAL: Connection Failed: Too many connections (Spine thread)
01/24/2008 03:50:00 AM - SYSTEM STATS: Time:0.1245 Method:spine Processes:1 Threads:4 Hosts:14 HostsPerProcess:14 DataSources:841 RRDsProcessed:0

The best one I think is this line:

Please make sure you have specified a valid MySQL database name in 'include/config.php''

config.php and global.php settings are correct - I have checked it. spine.conf is ok as well...

Rebooting does work at maximum for half an hour....but then the same errors appear

Alex

ame · Post by **ame** » Thu Jan 24, 2008 2:05 am

switching to cmd.php and the problems are disappearing....
Is there anywhere a newer spine which I can use for testing?

Alex

fmangeant · Post by **fmangeant** » Thu Jan 24, 2008 2:33 am

ame wrote:01/24/2008 03:52:01 AM - SPINE: Poller[0] FATAL: Connection Failed: Too many connections (Spine thread)
01/24/2008 03:52:01 AM - SPINE: Poller[0] ERROR: SS[999] Script Server did not start properly return message was: 'FATAL: Cannot connect to MySQL server on 'localhost'. Please make sure you have specified a valid MySQL database name in 'include/config.php''

Hi

did you configure spine.conf ?

ame · Post by **ame** » Thu Jan 24, 2008 2:54 am

as said before:

config.php and global.php settings are correct - I have checked it. spine.conf is ok as well...

Alex

fmangeant · Post by **fmangeant** » Thu Jan 24, 2008 3:02 am

Sorry

Can you increase the number of MySQL connections :

Code: Select all

set-variable = max_connections=1000

in my.cnf ?

ame · Post by **ame** » Thu Jan 24, 2008 3:03 am

no problem...

I still have max_connections=500
I think this should be enough, or not?

fmangeant · Post by **fmangeant** » Thu Jan 24, 2008 3:19 am

Maybe using a higher value for max_connections will help...

Your error comes from sql.c :

Code: Select all

thread_mutex_unlock(LOCK_MYSQL);

if (!success){
    die("FATAL: Connection Failed: %s", mysql_error(mysql));
}

I think Larry (aka TheWitness) will be able to find an answer.

ame · Post by **ame** » Thu Jan 24, 2008 3:22 am

how can I find out, if the spine.conf will be found by the spine executable?

At the compilation of spine the files has been installed automatically to
/usr/local/spine/bin/spine
and
/usr/local/spine/etc/spine.conf

Alex

fmangeant · Post by **fmangeant** » Thu Jan 24, 2008 3:31 am

By default Spine searchs in the current directory, in ../etc and in /etc

ame · Post by **ame** » Thu Jan 24, 2008 5:30 am

Hi,

I have now increased the max_connections to 1000 and have copied the spine.conf in the /etc to be sure that spine does find it.....

but without success

micky:~# ps -ax |grep cacti
Warning: bad ps syntax, perhaps a bogus '-'? See http://procps.sf.net/faq.html
2985 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
2988 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
3791 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
3795 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
4704 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
4707 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
6705 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
6709 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
7284 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
7294 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
7989 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
7992 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
8933 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
8936 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
9210 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
9230 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
9392 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
9395 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
9502 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
9515 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
9747 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
9793 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/script_server.php spine 0
10247 ? Ss 0:00 /bin/sh -c /usr/share/cacti/site/poller.php >/dev/null 2>/var/log/cacti/poller-error.log
10248 ? S 0:00 /usr/bin/php -q /usr/share/cacti/site/poller.php
10608 pts/0 S+ 0:00 grep cacti

when I make a grep to cacti threads I get more and more spine entries and inside a few hours the complete RAM is allocated from the spine threads...you can see there 22 entries but normally it should be only four...

Alex

fmangeant · Post by **fmangeant** » Thu Jan 24, 2008 5:33 am

Can you kill all the Spine processes, and run it once by hand :

Code: Select all

$ ./spine --verbosity=DEBUG

ame · Post by **ame** » Thu Jan 24, 2008 5:41 am

looks really normal....

micky:/usr/local/spine/bin# ./spine --verbosity=DEBUG
SPINE: Using spine config file [/etc/spine.conf]
SPINE: Version 0.8.7b starting
SPINE: Time: 11.2514 s, Threads: 4, Hosts: 37

Alex

fmangeant · Post by **fmangeant** » Thu Jan 24, 2008 5:57 am

Oups... Can you try that :

Code: Select all

$ ./spine --verbosity=5

ame · Post by **ame** » Thu Jan 24, 2008 6:30 am

it is a really long list - too much to display
but I think the important lines are the last ones:

01/24/2008 12:21:39 PM - SPINE: Poller[0] DEBUG: SQL:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (385,'hdd_total','2008- 01-24 12:21:39','8973778944'),(385,'hdd_used','2008-01-24 12:21:39','8604160000'),(390,'cpu','2008-01-24 12:21:39','2'),(392,'traffic_in','2008-01-24 12:21:39','1339123839'),(392,'traffic_out','2008-01-24 12:21:39','1492805027')'
01/24/2008 12:21:39 PM - SPINE: Poller[0] Host[36] DEBUG: HOST COMPLETE: About to Exit Host Polling Thread Function
01/24/2008 12:21:39 PM - SPINE: Poller[0] DEBUG: The Value of Active Threads is 0
01/24/2008 12:21:39 PM - SPINE: Poller[0] DEBUG: SQL:'replace into settings (name,value) values ('date',NOW())'
01/24/2008 12:21:39 PM - SPINE: Poller[0] DEBUG: SQL:'insert into poller_time (poller_id, start_time, end_time) values (0, NOW(), NOW())'
01/24/2008 12:21:39 PM - SPINE: Poller[0] DEBUG: Thread Cleanup Complete
01/24/2008 12:21:39 PM - SPINE: Poller[0] DEBUG: SS[0] Script Server Shutdown Started
01/24/2008 12:21:39 PM - SPINE: Poller[0] DEBUG: SS[1] Script Server Shutdown Started
01/24/2008 12:21:39 PM - SPINE: Poller[0] DEBUG: PHP Script Server Pipes Closed
01/24/2008 12:21:39 PM - SPINE: Poller[0] DEBUG: Allocated Variable Memory Freed
01/24/2008 12:21:39 PM - SPINE: Poller[0] SPINE: Net-SNMP API Shutdown Completed
01/24/2008 12:21:39 PM - SPINE: Poller[0] DEBUG: MYSQL Free & Close Completed
01/24/2008 12:21:39 PM - SPINE: Poller[0] Time: 9.3941 s, Threads: 4, Hosts: 37
micky:/usr/local/spine/bin# ./spine --verbosity=5 > test

That is the problem: it does work when you run spine once but over the time it goes crazy...
the process graph of the local machine grows and grows - at the end I had over 400 processes running - all from spine.

Alex

ame · Post by **ame** » Thu Jan 24, 2008 6:47 am

these are the first polls after a restart:

01/24/2008 12:46:05 PM - SYSTEM STATS: Time:3.7594 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:163 RRDsProcessed:119
01/24/2008 12:46:05 PM - SPINE: Poller[0] ERROR: A database insert failed! Error:'1062', SQL Fragment:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (376,'hdd_total','2008-01-24 12:46:04','8973778944'),(376,'hdd_used','2008-01-24 12:46:04','8604160000'),(381,'cpu','2008-01-24 12:46:04','1'),(383,'traffic_in','2008-01-24 12:46:04','2303464986'),(383,'traffic_out','2008-01-24 12:46:04','2240791552')'
01/24/2008 12:46:02 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Potential Data Source Issues for Data Sources: cpu(DS[15]), traffic_in(DS[19]), traffic_out(DS[19]), hdd_total(DS[264]), hdd_used(DS[264]), traffic_in(DS[268]), traffic_out(DS[268]), hdd_total(DS[270]), hdd_used(DS[270]), traffic_in(DS[273]), traffic_out(DS[273]), hdd_total(DS[276]), hdd_used(DS[276]), traffic_in(DS[279]), traffic_out(DS[279]), hdd_total(DS[288]), hdd_used(DS[288]), traffic_in(DS[292]), traffic_out(DS[292]), traffic_in(DS[293]), traffic_out(DS[293]), traffic_in(DS[294]), traffic_out(DS[294])
01/24/2008 12:46:01 PM - SYSTEM STATS: Time:0.5999 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:159 RRDsProcessed:2
01/24/2008 12:46:01 PM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting.
01/24/2008 12:46:00 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Potential Data Source Issues for Data Sources: hdd_total(DS[173]), hdd_used(DS[173]), cpu(DS[178]), cpu(DS[183]), traffic_in(DS[185]), traffic_out(DS[185]), traffic_in(DS[186]), traffic_out(DS[186])
01/24/2008 12:45:06 PM - SYSTEM STATS: Time:4.4243 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:163 RRDsProcessed:144
01/24/2008 12:45:06 PM - SPINE: Poller[0] ERROR: A database insert failed! Error:'1062', SQL Fragment:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (324,'hdd_total','2008-01-24 12:45:04','4294049792'),(324,'hdd_used','2008-01-24 12:45:04','3805937664'),(329,'traffic_in','2008-01-24 12:45:04','151967924'),(329,'traffic_out','2008-01-24 12:45:04','3395859076')'
01/24/2008 12:45:06 PM - SPINE: Poller[0] ERROR: A database insert failed! Error:'1062', SQL Fragment:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (296,'hdd_total','2008-01-24 12:45:03','41945116672'),(296,'hdd_used','2008-01-24 12:45:03','7646396416'),(301,'cpu','2008-01-24 12:45:03','14'),(302,'traffic_in','2008-01-24 12:45:03','140258850'),(302,'traffic_out','2008-01-24 12:45:03','4115361147')'
01/24/2008 12:45:05 PM - SPINE: Poller[0] ERROR: A database insert failed! Error:'1062', SQL Fragment:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (253,'hdd_total','2008-01-24 12:45:04','26217644032'),(253,'hdd_used','2008-01-24 12:45:04','18281799680'),(258,'cpu','2008-01-24 12:45:04','8'),(261,'traffic_in','2008-01-24 12:45:04','136458441'),(261,'traffic_out','2008-01-24 12:45:04','3361953746')'
01/24/2008 12:45:04 PM - SPINE: Poller[0] ERROR: A database insert failed! Error:'1062', SQL Fragment:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (288,'hdd_total','2008-01-24 12:45:03','4682285056'),(288,'hdd_used','2008-01-24 12:45:03','857538560'),(292,'traffic_in','2008-01-24 12:45:03','257456898'),(292,'traffic_out','2008-01-24 12:45:03','3669138631'),(293,'traffic_in','2008-01-24 12:45:03','2368765395'),(293,'traffic_out','2008-01-24 12:45:03','612385810'),(294,'traffic_in','2008-01-24 12:45:03','452824013'),(294,'traffic_out','2008-01-24 12:45:03','1178444148')'
01/24/2008 12:45:04 PM - SPINE: Poller[0] ERROR: A database insert failed! Error:'1062', SQL Fragment:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (228,'hdd_total','2008-01-24 12:45:04','4293984256'),(228,'hdd_used','2008-01-24 12:45:04','1842216960'),(233,'traffic_in','2008-01-24 12:45:04','4200216837'),(233,'traffic_out','2008-01-24 12:45:04','3350346124')'
01/24/2008 12:45:04 PM - SPINE: Poller[0] ERROR: A database insert failed! Error:'1062', SQL Fragment:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (234,'hdd_total','2008-01-24 12:45:04','19312922624'),(234,'hdd_used','2008-01-24 12:45:04','13040898048'),(238,'traffic_in','2008-01-24 12:45:04','680285645'),(238,'traffic_out','2008-01-24 12:45:04','408266692')'
01/24/2008 12:45:01 PM - SYSTEM STATS: Time:0.4559 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:159 RRDsProcessed:1
01/24/2008 12:45:01 PM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting.
01/24/2008 12:45:00 PM - SYSTEM STATS: Time:239.1090 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:159 RRDsProcessed:68
01/24/2008 12:45:00 PM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting.
01/24/2008 12:40:08 PM - SYSTEM STATS: Time:6.7302 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:159 RRDsProcessed:96
01/24/2008 12:40:01 PM - SYSTEM STATS: Time:59.9335 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:159 RRDsProcessed:69
01/24/2008 12:40:01 PM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting.
01/24/2008 12:38:07 PM - SYSTEM STATS: Time:5.5983 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:159 RRDsProcessed:96
01/24/2008 12:37:08 PM - SYSTEM STATS: Time:6.7285 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:159 RRDsProcessed:90
01/24/2008 12:36:06 PM - SYSTEM STATS: Time:4.5968 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:159 RRDsProcessed:93
01/24/2008 12:35:08 PM - SYSTEM STATS: Time:6.6876 Method:spine Processes:4 Threads:4 Hosts:34 HostsPerProcess:9 DataSources:159 RRDsProcessed:93

you can see that the first polls are ok, but then the sh... begins

Alex

Cacti

Spine trouble?

Spine trouble?

Re: Spine trouble?

Who is online