Cacti 0.8.6 - 'cacti' 'cactiuser' MySQL duplcate issues?

Post by **raX** » Fri Sep 17, 2004 10:09 am

Looking over your log output, I noticed that the value of your 'threads' variable is set to '1'. This will cause cactid to run much slower than it normally would. I recommend a value of around '10'.

To change, go to Settings -> Poller -> "Maximum Threads per Process"

I have a feeling that this change will cause your poller runtime to reduce drastically.

About your update problem... the 0.8.6a pre-release version should contain additional RRDTool debug information in the log. While running the poller (log level = DEBUG) I recommend that you tail your Cacti log while grepping for "RRDTOOL". This should indicate if RRDTool is reporting any problems when trying to update your .rrd files.

-Ian

monideth · Post by **monideth** » Fri Sep 17, 2004 10:23 am

raX,

I have tried different combinations of process and threads for cmd and cactid pollers.

However, now I have set it to 1 process and 10 threads.

You may be concerned to hear that I do not get any RRDTOOL debugs statements in my cacti.log!!! And before you ask - yes I have set the logging level to DEBUG!

Where within the logs should it indicate what path it is using for the rrdtool. Withing the Cacti web management Configuration->Settings->Paths it thinks it should be using "/usr/bin/rrdtool" I can confirm this is the correct path:

Code: Select all

[root@cacti-unl log]# /usr/bin/rrdtool
RRDtool 1.0.49  Copyright 1997-2004 by Tobias Oetiker <tobi@oetiker.ch>

Usage: rrdtool [options] command command_options

Valid commands: create, update, graph, dump, restore,
                last, info, fetch, tune, resize, xport

RRDtool is distributed under the Terms of the GNU General
Public License Version 2. (www.gnu.org/copyleft/gpl.html)

For more information read the RRD manpages

Regards,

Mon

Post by **raX** » Fri Sep 17, 2004 10:38 am

Weird... you are using the pre-release, right? Does running the following command in your Cacti directory give you the same output as below?

Code: Select all

[root@radish cacti-0.8.6a]# grep 'cacti_log("RRDTOOL' lib/rrd.php 
                                        cacti_log("RRDTOOL: " . $line);
                                        cacti_log("RRDTOOL: " . $line);

-Ian

monideth · Post by **monideth** » Fri Sep 17, 2004 10:44 am

raX,

Yes I get the same repsonse!:

Code: Select all

[root@cacti-unl cacti]# grep 'cacti_log("RRDTOOL' lib/rrd.php
                                        cacti_log("RRDTOOL: " . $line);
                                        cacti_log("RRDTOOL: " . $line);
[root@cacti-unl cacti]#

Note, when I run the poller from command line I do it under the 'cacti' account - I 'su cacti' in to it first and then run 'php poller.php'

Post by **TheWitness** » Fri Sep 17, 2004 3:27 pm

monideth,

It is apparant to me looking over what little of your log output I am seeing that poller.php is crashing at some point. I would like to ask you to verify that your PHP relase is stable. Goto the php.net web site to verify. You may even want to change versions. Then, I would like to have you insure that you are in fact running php cli "php -v".

Thanks,

TheWitness

Post by **TheWitness** » Fri Sep 17, 2004 3:42 pm

monideth,

How much of a programmer are you. I would normally perform a dialog with you via AIM or MSM. However, I have to go to a fair tonight and then on a Boy Scout trip this weekend until Sunday.

To debug this issue is not too difficult. The method that I use is to edit the function in which you are experiencing the hangup. In this case it will either be poller.php or lib/poller.php. Method involves adding statements or "breakpoints" using the cacti_log function.

The first thing I want you to do is change the "sleep(1);" statement in poller.php to "usleep(1000000);". If that does not change it, go back.

Then I want you to start placing "cacti_log" statements strategically withing the process_poller_output function contained in lib/poller.php and cascade from there.

I use statments like "cacti_log("I'm at section 1")" and then "cacti_log("Fooey"), etc. Just so that I know where I am. What you will do is clear the log and then run poller.php from the command line and review your out, place additional "cacti_log" statements, clear the log and run again....

Eventually, you will narrow the error down to a section. When you have that section, let post the information and well finish it up for you. If you figure it out yourself, great, keep us posed.

TheWitness

monideth · Post by **monideth** » Sat Sep 18, 2004 3:08 am

TheWitness

I am no programmer! However I did try to debug it by putting in some debug statements last night.

I eventually came stuck at the following piece of code - in lib/poller.php:

Code: Select all

[root@cacti-unl lib]# vi poller.php
function process_poller_output($rrdtool_pipe) {
        global $config;

        include_once($config["library_path"] . "/rrd.php");
print "####MONTEST 6 - lib/poller.php - in process_poller_output() - calling db_fetch_assoc() ####\n";
        /* create/update the rrd files */
        $results = db_fetch_assoc("select
                poller_output.output,
                poller_output.time,
                poller_output.local_data_id,
                poller_item.rrd_path,
                poller_item.rrd_name,
                poller_item.rrd_num
                from poller_output,poller_item
                where (poller_output.local_data_id=poller_item.local_data_id and poller_output.rrd_name=poller_item.rrd_name)");
print "####MONTEST 6 - lib/poller.php - in process_poller_output() - called db_fetch_assoc() ####\n";
        if (sizeof($results) > 0) {

As you can see I have put in some 'print' statements to indicate where within the code the process is in.

The output from cacti/poller.php is:

Code: Select all

09/18/2004 08:03:12 AM - POLLER: Poller[0] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/cactid/bin/cactid, ARGS:  0 111]
####MONTEST1####
####MONTEST3####
Waiting on 1/1 pollers.
####MONTEST 4 - poller.php - calling process_poller_output() ####
####MONTEST 6 - lib/poller.php - in process_poller_output() - calling db_fetch_assoc() ####

It seems to get stuck here. I don't know whether the points I am printing at are valid - but it seems to me that it is not returining from db_fetch_assoc() inside lib/poller.php.

That is as far as I got - my programming skills stops there!

I will check out the PHP version issue when I can and will report back.

Regards,

Mon

monideth · Post by **monideth** » Sat Sep 18, 2004 3:16 am

TheWitness,

From what I can see my PHP version is stable and the latest for Fedora Core 2:

Code: Select all

[root@cacti-unl lib]# php -v
PHP 4.3.8 (cgi) (built: Jul 16 2004 09:23:33)
Copyright (c) 1997-2004 The PHP Group
Zend Engine v1.3.0, Copyright (c) 1998-2004 Zend Technologies
[root@cacti-unl lib]#

Code: Select all

[root@cacti-unl monideth]# rpm -qa | grep php
php-imap-4.3.8-2.1
php-ldap-4.3.8-2.1
php-snmp-4.3.8-2.1
php-mbstring-4.3.8-2.1
php-pear-4.3.8-2.1
php-4.3.8-2.1
php-mysql-4.3.8-2.1
[root@cacti-unl monideth]#

However, I could try to force an uninstall and install of these RPM modules again.

Please note that after upgrade from Fedora Core 1 to Core 2 Cacti 0.8.5a was working OK - it was only whenI upgraded to Cacti 0.8.6 that I had these problems.

Regards,

Mon

Post by **raX** » Sat Sep 18, 2004 10:08 pm

This is sort of a shot in the dark, but I think poller.php is exceeding PHP's 8 MB maximum memory limit when it is calling db_fetch_assoc(). Try putting the following line of code somewhere near the top of poller.php:

Code: Select all

ini_set("memory_limit", "32M");

-Ian

monideth · Post by **monideth** » Sun Sep 19, 2004 2:55 am

raX

Which poller.php do you refer to? There are two:

/var/www/html/caci/poller.php
/var/www/html/caci/lib/poller.php

Regards,

Mon

monideth · Post by **monideth** » Sun Sep 19, 2004 4:35 am

raX / TheWitness

I have done some more debugging.

I have set the code that raX suggest - but with a higher value - in cacti/poller.php:

Code: Select all

ini_set("memory_limit", "128M");

I have changed my debugging output to use cacti_log().

My output from cacti/poller.php hangs at:

Code: Select all

bash-2.05b$ php poller.php
Content-type: text/html
X-Powered-By: PHP/4.3.8

09/19/2004 09:24:05 AM - MONTEST: Poller[0] cacti/poller.php - start of file
09/19/2004 09:24:05 AM - MONTEST: Poller[0] cacti/poller.php - creating polling_hosts
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - start of function
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - calling Execute()
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - return from Execute()
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - inside if query
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - returning data
09/19/2004 09:24:05 AM - MONTEST: Poller[0] cacti/poller.php - created polling_hosts
09/19/2004 09:24:05 AM - POLLER: Poller[0] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/cactid/bin/cactid, ARGS:  0 111]
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - start of function
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - calling Execute()
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - return from Execute()
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - inside if query
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - returning data
09/19/2004 09:24:05 AM - MONTEST: Poller[0] cacti/poller.php - else of if sizeof polling_items equal process_file_number
Waiting on 1/1 pollers.
09/19/2004 09:24:05 AM - MONTEST: Poller[0] cacti/poller.php - calling process_poller_output()

09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/poller.php - in process_poller_output() - calling db_fetch_assoc()
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - start of function
09/19/2004 09:24:05 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - calling Execute()
09/19/2004 09:24:47 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - return from Execute()
09/19/2004 09:24:47 AM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - inside if query

The db_fetch_assoc() funstion in lib/database.php is:

Code: Select all

function db_fetch_assoc($sql) {
        global $cnn_id;
cacti_log(sprintf("lib/database.php - in db_fetch_assoc() - start of function"),true,"MONTEST");
        if (!$cnn_id) { db_connect(); }

        $data = array();
        $cnn_id->SetFetchMode(ADODB_FETCH_ASSOC);
        cacti_log(sprintf("lib/database.php - in db_fetch_assoc() - calling Execute()"),true,"MONTEST");
        $query = $cnn_id->Execute($sql);
        cacti_log(sprintf("lib/database.php - in db_fetch_assoc() - return from Execute()"),true,"MONTEST");
        if ($query) {
                cacti_log(sprintf("lib/database.php - in db_fetch_assoc() - inside if query"),true,"MONTEST");
                while ((!$query->EOF) && ($query)) {
                        $data{sizeof($data)} = $query->fields;
                        $query->MoveNext();
                }
                cacti_log(sprintf("lib/database.php - in db_fetch_assoc() - returning data"),true,"MONTEST");
                return($data);
        }
}

As you can see it seems that the while loop never gets broken and this no data is returned.

However, from the debug it seems this is the 3rd time that the function has been called - the second time the while loop is broken and the data is returned.

I assume this is where the process is hanging - it is stuck within the while loop.

Any suggestions?

Regards,

Mon

monideth · Post by **monideth** » Sun Sep 19, 2004 11:06 am

I did some debugging and tried to be patient - it seems that eventually it does come out of teh while loop:

Code: Select all

09/19/2004 03:37:09 PM - CACTID: Poller[0] Host[47] DEBUG: HOST COMPLETE: About to Exit Host Polling Thread Function
09/19/2004 03:37:09 PM - CACTID: Poller[0] DEBUG: The Value of Active Threads is 0
09/19/2004 03:37:09 PM - CACTID: Poller[0] DEBUG: SQLCMD: replace into settings (name,value) values ('date',NOW())
09/19/2004 03:37:09 PM - CACTID: Poller[0] DEBUG: SQLCMD: insert into poller_time (poller_id, start_time, end_time) values (0,
 NOW(), NOW())
09/19/2004 03:37:09 PM - CACTID: Poller[0] DEBUG: Thread Cleanup Complete
09/19/2004 03:37:09 PM - CACTID: Poller[0] DEBUG: SNMP Cleanup Complete
09/19/2004 03:37:09 PM - CACTID: Poller[0] DEBUG: PHP Script Server Shutdown Started
09/19/2004 03:37:09 PM - CACTID: Poller[0] DEBUG: PHP Script Server Pipes Closed
09/19/2004 03:37:09 PM - CACTID: Poller[0] DEBUG: Allocated Variable Memory Freed
09/19/2004 03:37:09 PM - CACTID: Poller[0] DEBUG: MYSQL Free & Close Completed
09/19/2004 03:37:09 PM - CACTID: Poller[0] Time: 406.7946 s, Threads: 10, Hosts: 9
09/19/2004 03:37:10 PM - PHPSVR: Poller[0] DEBUG: PHP Script Server Shutdown request received, exiting
09/19/2004 03:39:06 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - returning data
09/19/2004 03:39:07 PM - MONTEST: Poller[0] lib/poller.php - in process_poller_output() - return from db_fetch_assoc()
09/19/2004 03:39:07 PM - MONTEST: Poller[0] lib/poller.php - in process_poller_output() - test for results of db_fetch_assoc()
09/19/2004 03:39:12 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - start of function
09/19/2004 03:39:12 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - calling Execute()
09/19/2004 03:39:28 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - return from Execute()
09/19/2004 03:39:28 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - inside if query
09/19/2004 03:39:28 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - returning data
09/19/2004 03:39:29 PM - POLLER: Poller[0] Parsed MULTI output field '1min:2.86' [map 1min->load_1min]
09/19/2004 03:39:29 PM - POLLER: Poller[0] Parsed MULTI output field '5min:1.15' [map 5min->load_5min]
09/19/2004 03:39:29 PM - POLLER: Poller[0] Parsed MULTI output field '10min:1.87' [map 10min->load_15min]
09/19/2004 03:39:29 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - start of function
09/19/2004 03:39:29 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - calling Execute()
09/19/2004 03:39:29 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - return from Execute()
09/19/2004 03:39:29 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - inside if query
09/19/2004 03:39:29 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - returning data
09/19/2004 03:39:29 PM - POLLER: Poller[0] Parsed MULTI output field '1min:0.81' [map 1min->load_1min]
09/19/2004 03:39:29 PM - POLLER: Poller[0] Parsed MULTI output field '5min:0.62' [map 5min->load_5min]
09/19/2004 03:39:29 PM - POLLER: Poller[0] Parsed MULTI output field '10min:1.75' [map 10min->load_15min]

The poller started at 03:30 - so it took 9 mins to come out of the while loop!

However, now it is giving the 'Parsed MULTI' messages. This continues for a long time and does not seem to change. Eventually is stops outputting these messages but does nothing else - not that I can see anyway:

Code: Select all

09/19/2004 03:45:11 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - start of function
09/19/2004 03:45:11 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - calling Execute()
09/19/2004 03:45:11 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - return from Execute()
09/19/2004 03:45:11 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - inside if query
09/19/2004 03:45:11 PM - MONTEST: Poller[0] lib/database.php - in db_fetch_assoc() - returning data
09/19/2004 03:45:11 PM - POLLER: Poller[0] Parsed MULTI output field '1min:8.79' [map 1min->load_1min]
09/19/2004 03:45:11 PM - POLLER: Poller[0] Parsed MULTI output field '5min:5.29' [map 5min->load_5min]
09/19/2004 03:45:11 PM - POLLER: Poller[0] Parsed MULTI output field '10min:3.18' [map 10min->load_15min]

Why is is going soooo sloooowlyyyy?!

Regards,

Mon

Guest · Post by **Guest** » Sun Sep 19, 2004 2:29 pm

Now, I don't get this at all!

I have removed (hashed out) all my debugs and removed the extra line code suggested by raX and it is all working gain!

I can see the RRD debug statements in the standard output and cacti.log log file.

The graphs seems to be updating agian now.

I will now set it to run under cron.d/cacti and see how it goes.

I am not sure what I've done - as I said only removed my log messages - but this was only added in when I had the problem!

raX / TheWitness - I feel a bit emabarassed

for taking up your time on this.

I will reboot the server to see whether it reverts back to being a problem - just in case something in memory is keeping it working OK!

Regards,

Mon

monideth · Post by **monideth** » Sun Sep 19, 2004 2:29 pm

Sorry - that was me posting the above message

Post by **TheWitness** » Sun Sep 19, 2004 2:35 pm

Mon,

You learned a lot. I hope all continues to improve with your install.

TheWitness

Cacti 0.8.6 - 'cacti' 'cactiuser' MySQL duplcate issues?

Who is online