Spine 0.8.7d-pre3 Available for Testing

Important information about Cacti developments that all users should be interested in.

Moderators: Developers, Moderators

User avatar
TheWitness
Developer
Posts: 17047
Joined: Tue May 14, 2002 5:08 pm
Location: MI, USA
Contact:

Post by TheWitness »

Do you have a few minutes for a gotomeeting today? PM me.

TheWitness
True understanding begins only when we realize how little we truly understand...

Life is an adventure, let yours begin with Cacti!

Author of dozens of Cacti plugins and customization's. Advocate of LAMP, MariaDB, IBM Spectrum LSF and the world of batch. Creator of IBM Spectrum RTM, author of quite a bit of unpublished work and most of Cacti's bugs.
_________________
Official Cacti Documentation
GitHub Repository with Supported Plugins
Percona Device Packages (no support)
Interesting Device Packages


For those wondering, I'm still here, but lost in the shadows. Yearning for less bugs. Who want's a Cacti 1.3/2.0? Streams anyone?
Jacek_nykis
Posts: 23
Joined: Fri Jul 20, 2007 10:24 am

Post by Jacek_nykis »

Hi all,

I was doing some tests with this version and I am getting strange results as well. Spine does not segfault but I see exactly the same gaps in some graphs. What is strange some hosts are almost unaffected (one, maybe two gaps a day) and some of them show only about 20% of graphs.

Logs suggest SNMP timeouts but when I run polling manually everything seems fine for given host.

Below two debug logfile dumps one for successful manual polling from command line and one output from automatic invocation which failed. For automatic one I removed most of the output and left what I thought was important (I have almost 200 hosts in my installation). If you would like to see full dump please let me know.
Host ID in question is 194.

Thank you for any ideas.

#######################
Successful polling:

04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'path_php_binary''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The path_php variable is /usr/bin/php
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'availability_method''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The availability_method variable is 2
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_recovery_count''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The ping_recovery_count variable is 1
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_failure_count''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The ping_failure_count variable is 2
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_method''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The ping_method variable is 2
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_retries''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The ping_retries variable is 1
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_timeout''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The ping_timeout variable is 500
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'log_perror''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The log_perror variable is 1
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'log_pwarn''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The log_pwarn variable is 0
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'log_pstats''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The log_pstats variable is 0
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'max_threads''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The threads variable is 4
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'poller_interval''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The polling interval is 300 seconds
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'concurrent_processes''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The number of concurrent processes is 4
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'script_timeout''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The script timeout is 25
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'php_servers''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The number of php script servers to run is 2
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT action FROM poller_item WHERE action=2 AND host_id BETWEEN 194 AND 194 LIMIT 1'
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: StartHost='194', EndHost='194', TotalPHPScripts='0'
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The PHP Script Server is Not Required
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'max_get_size''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The Maximum SNMP OID Get Size is 60
04/22/2009 12:37:24 PM - SPINE: Poller[0] SPINE: Initializing Net-SNMP API
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: SNMP Header Version is 5.3.1
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: SNMP Library Version is 5.3.1
04/22/2009 12:37:24 PM - SPINE: Poller[0] SPINE: Initializing PHP Script Server(s)
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT id FROM host WHERE disabled='' AND id BETWEEN 194 AND 194 ORDER BY id'
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: Initial Value of Active Threads is 0
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: Valid Thread to be Created
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The Value of Active Threads is 1
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: In Poller, About to Start Polling of Host
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT snmp_port, count(snmp_port) FROM poller_item WHERE host_id=0 AND rrd_next_step < 0 GROUP BY snmp_port'
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT action, hostname, snmp_community, snmp_version, snmp_username, snmp_password, rrd_name, rrd_path, arg1, arg2, arg3, local_data_id, rrd_num, snmp_port, snmp_timeout, snmp_auth_protocol, snmp_priv_passphrase, snmp_priv_protocol, snmp_context FROM poller_item WHERE host_id=0 and rrd_next_step <=0 ORDER by snmp_port'
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'UPDATE poller_item SET rrd_next_step=rrd_next_step-300 WHERE host_id=0'
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'UPDATE poller_item SET rrd_next_step=rrd_step-300 WHERE rrd_next_step < 0 and host_id=0'
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[0] DEBUG: HOST COMPLETE: About to Exit Host Polling Thread Function
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: Valid Thread to be Created
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The Value of Active Threads is 2
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: In Poller, About to Start Polling of Host
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT id, hostname, snmp_community, snmp_version, snmp_username, snmp_password, snmp_auth_protocol, snmp_priv_passphrase, snmp_priv_protocol, snmp_context, snmp_port, snmp_timeout, max_oids, availability_method, ping_method, ping_port, ping_timeout, ping_retries, status, status_event_count, status_fail_date, status_rec_date, status_last_error, min_time, max_time, cur_time, avg_time, total_polls, failed_polls, availability FROM host WHERE id=194'
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEBUG: The Value of Active Threads is 1
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] SNMP Result: Host responded to SNMP
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'UPDATE host SET status='3', status_event_count='0', status_fail_date='2009-04-22 12:20:00', status_rec_date='2009-04-22 12:36:00', status_last_error='Host did not respond to SNMP', min_time='0.000000', max_time='0.000000', cur_time='0.000000', avg_time='0.000000', total_polls='1114', failed_polls='1109', availability='0.4488' WHERE id='194''
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT data_query_id, action, op, assert_value, arg1 FROM poller_reindex WHERE host_id=194'
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] Host has no information for recache.
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT snmp_port, count(snmp_port) FROM poller_item WHERE host_id=194 AND rrd_next_step < 0 GROUP BY snmp_port'
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT action, hostname, snmp_community, snmp_version, snmp_username, snmp_password, rrd_name, rrd_path, arg1, arg2, arg3, local_data_id, rrd_num, snmp_port, snmp_timeout, snmp_auth_protocol, snmp_priv_passphrase, snmp_priv_protocol, snmp_context FROM poller_item WHERE host_id=194 and rrd_next_step <=0 ORDER by snmp_port'
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'UPDATE poller_item SET rrd_next_step=rrd_next_step-300 WHERE host_id=194'
04/22/2009 12:37:24 PM - SPINE: Poller[0] DEVDBG: SQL:'UPDATE poller_item SET rrd_next_step=rrd_step-300 WHERE rrd_next_step < 0 and host_id=194'
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] NOTE: There are '12' Polling Items for this Host
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DEBUG: The POPEN returned the following File Descriptor 7
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DS[3193] SCRIPT: perl /var/www/html/cacti/scripts/ws_apachestats.pl xxx.xxx.xxx.xxx, output: apache_total_hits:772851 apache_total_kbytes:421399 apache_busy_workers:1 apache_idle_workers:79 thread_O:176 threadC:0 threadD:0 threadG:0 threadI:0 threadK:0 threadL:0 threadR:0 threadS:0 threadW:1 thread_W:79 apache_cpuload:3.54877
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DS[3197] SNMP: v3: xxx.xxx.xxx.xxx, dsname: traffic_out, oid: .1.3.6.1.2.1.2.2.1.16.3, value: 2420905756
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DS[3192] SNMP: v3: xxx.xxx.xxx.xxx, dsname: load_1min, oid: .1.3.6.1.4.1.2021.10.1.3.1, value: 0.00
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DS[3191] SNMP: v3: xxx.xxx.xxx.xxx, dsname: cpu_user, oid: .1.3.6.1.4.1.2021.11.50.0, value: 136762737
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DS[3189] SNMP: v3: xxx.xxx.xxx.xxx, dsname: cpu_nice, oid: .1.3.6.1.4.1.2021.11.51.0, value: 45609
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DS[3190] SNMP: v3: xxx.xxx.xxx.xxx, dsname: cpu_system, oid: .1.3.6.1.4.1.2021.11.52.0, value: 18414355
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DEBUG: The POPEN returned the following File Descriptor 7
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DS[3194] SCRIPT: perl /var/www/html/cacti/scripts/ws_apachestats.pl xxx.xxx.xxx.xxx, output: apache_total_hits:772852 apache_total_kbytes:421399 apache_busy_workers:1 apache_idle_workers:79 thread_O:176 threadC:0 threadD:0 threadG:0 threadI:0 threadK:0 threadL:0 threadR:0 threadS:0 threadW:1 thread_W:79 apache_cpuload:3.54877
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DEBUG: The POPEN returned the following File Descriptor 7
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DS[3195] SCRIPT: perl /var/www/html/cacti/scripts/ws_apachestats.pl xxx.xxx.xxx.xxx, output: apache_total_hits:772853 apache_total_kbytes:421399 apache_busy_workers:1 apache_idle_workers:79 thread_O:176 threadC:0 threadD:0 threadG:0 threadI:0 threadK:0 threadL:0 threadR:0 threadS:0 threadW:1 thread_W:79 apache_cpuload:3.54877
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DS[3197] SNMP: v3: xxx.xxx.xxx.xxx, dsname: traffic_in, oid: .1.3.6.1.2.1.2.2.1.10.3, value: 229180221
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DS[3196] SNMP: v3: xxx.xxx.xxx.xxx, dsname: traffic_in, oid: .1.3.6.1.2.1.2.2.1.10.2, value: 2240575772
04/22/2009 12:37:24 PM - SPINE: Poller[0] Host[194] DEBUG: The POPEN returned the following File Descriptor 7
04/22/2009 12:37:25 PM - SPINE: Poller[0] Host[194] DS[3188] SCRIPT: /usr/bin/perl /var/www/html/cacti/scripts/lvm_netstat_tcp.pl xxx.xxx.xxx.xxx 3 public 161 500 xxxxxx xxxxxx, output: established:80 listen:0 timewait:153 timeclose:0 finwait1:0 finwait2:0 synsent:0 synrecv:0 closewait:0
04/22/2009 12:37:25 PM - SPINE: Poller[0] Host[194] DS[3196] SNMP: v3: xxx.xxx.xxx.xxx, dsname: traffic_out, oid: .1.3.6.1.2.1.2.2.1.16.2, value: 702558900
04/22/2009 12:37:25 PM - SPINE: Poller[0] DEVDBG: SQL:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (3197,'traffic_out','2009-04-22 12:37:24','2420905756'),(3193,'','2009-04-22 12:37:24','apache_total_hits:772851 apache_total_kbytes:421399 apache_busy_workers:1 apache_idle_workers:79 thread_O:176 threadC:0 threadD:0 threadG:0 threadI:0 threadK:0 threadL:0 threadR:0 threadS:0 threadW:1 thread_W:79 apache_cpuload:3.54877'),(3192,'load_1min','2009-04-22 12:37:24','0.00'),(3191,'cpu_user','2009-04-22 12:37:24','136762737'),(3189,'cpu_nice','2009-04-22 12:37:24','45609'),(3190,'cpu_system','2009-04-22 12:37:24','18414355'),(3197,'traffic_in','2009-04-22 12:37:24','229180221'),(3194,'','2009-04-22 12:37:24','apache_total_hits:772852 apache_total_kbytes:421399 apache_busy_workers:1 apache_idle_workers:79 thread_O:176 threadC:0 threadD:0 threadG:0 threadI:0 threadK:0 threadL:0 threadR:0 threadS:0 threadW:1 thread_W:79 apache_cpuload:3.54877'),(3195,'','2009-04-22 12:37:24','apache_total_hits:772853 apache_total_kbytes:421399 apache_busy_worke'
04/22/2009 12:37:25 PM - SPINE: Poller[0] Host[194] DEBUG: HOST COMPLETE: About to Exit Host Polling Thread Function
04/22/2009 12:37:25 PM - SPINE: Poller[0] DEBUG: The Value of Active Threads is 0
04/22/2009 12:37:25 PM - SPINE: Poller[0] DEVDBG: SQL:'replace into settings (name,value) values ('date',NOW())'
04/22/2009 12:37:25 PM - SPINE: Poller[0] DEVDBG: SQL:'insert into poller_time (poller_id, start_time, end_time) values (0, NOW(), NOW())'
04/22/2009 12:37:25 PM - SPINE: Poller[0] DEBUG: Thread Cleanup Complete
04/22/2009 12:37:25 PM - SPINE: Poller[0] DEBUG: PHP Script Server Pipes Closed
04/22/2009 12:37:25 PM - SPINE: Poller[0] DEBUG: Allocated Variable Memory Freed
04/22/2009 12:37:25 PM - SPINE: Poller[0] DEBUG: MYSQL Free & Close Completed
04/22/2009 12:37:25 PM - SPINE: Poller[0] Time: 0.6647 s, Threads: 4, Hosts: 2

################################################################
Failed automatic polling

04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT name, file, function FROM plugin_hooks WHERE status = 1 AND hook = 'config_arrays'"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT name, file, function FROM plugin_hooks WHERE status = 1 AND hook = 'config_settings'"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT name, file, function FROM plugin_hooks WHERE status = 1 AND hook = 'valid_host_fields'"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT name, file, function FROM plugin_hooks WHERE status = 1 AND hook = 'config_form'"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT name, file, function FROM plugin_hooks WHERE status = 1 AND hook = 'config_insert'"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT name, file, function FROM plugin_hooks WHERE status = 1 AND hook = 'poller_top'"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Cell: "SELECT COUNT(*) FROM poller_item WHERE rrd_next_step<=0"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT host_id, COUNT(*) AS data_sources FROM poller_item WHERE rrd_next_step<=0 GROUP BY host_id ORDER BY host_id"
04/22/2009 12:35:01 PM - POLLER: Poller[0] NOTE: Poller Int: '300', Cron Int: '300', Time Since Last: '300', Max Runtime '298', Poller Runs: '1'
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Exec: "REPLACE INTO settings (name,value) VALUES ('poller_lastrun',1240400101)"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT id FROM host WHERE disabled = '' ORDER BY id"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Exec: "REPLACE INTO settings (name,value) VALUES ('path_webroot','/var/www/html/cacti')"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Exec: "TRUNCATE TABLE poller_time"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT local_data_id, rrd_name FROM poller_output"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT name, file, function FROM plugin_hooks WHERE status = 1 AND hook = 'poller_command_args'"
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'path_php_binary''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The path_php variable is /usr/bin/php
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'availability_method''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The availability_method variable is 2
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_recovery_count''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The ping_recovery_count variable is 1
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_failure_count''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The ping_failure_count variable is 2
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_method''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The ping_method variable is 2
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_retries''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The ping_retries variable is 1
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_timeout''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The ping_timeout variable is 500
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'log_perror''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The log_perror variable is 1
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'log_pwarn''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The log_pwarn variable is 0
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'log_pstats''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The log_pstats variable is 0
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'max_threads''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The threads variable is 4
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'poller_interval''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The polling interval is 300 seconds
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'concurrent_processes''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The number of concurrent processes is 4
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'script_timeout''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The script timeout is 25
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'php_servers''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The number of php script servers to run is 2
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT action FROM poller_item WHERE action=2 AND host_id BETWEEN 0 AND 49 LIMIT 1'
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: StartHost='0', EndHost='49', TotalPHPScripts='1'
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The PHP Script Server is Required
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'max_get_size''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The Maximum SNMP OID Get Size is 60
04/22/2009 12:35:01 PM - SPINE: Poller[0] SPINE: Initializing Net-SNMP API
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: SNMP Header Version is 5.3.1
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: SNMP Library Version is 5.3.1
04/22/2009 12:35:01 PM - SPINE: Poller[0] SPINE: Initializing PHP Script Server(s)
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: SS[0] PHP Script Server Routine Starting
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: SS[0] PHP Script Server About to FORK Child Process
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: SS[0] PHP Script Server Child FORK Success
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'path_php_binary''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The path_php variable is /usr/bin/php
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'availability_method''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The availability_method variable is 2
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_recovery_count''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The ping_recovery_count variable is 1
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_failure_count''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The ping_failure_count variable is 2
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_method''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The ping_method variable is 2
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_retries''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The ping_retries variable is 1
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'ping_timeout''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The ping_timeout variable is 500
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'log_perror''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The log_perror variable is 1
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'log_pwarn''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The log_pwarn variable is 0
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'log_pstats''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The log_pstats variable is 0
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'max_threads''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The threads variable is 4
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'poller_interval''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The polling interval is 300 seconds
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'concurrent_processes''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The number of concurrent processes is 4
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'script_timeout''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The script timeout is 25
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'php_servers''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The number of php script servers to run is 2
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT action FROM poller_item WHERE action=2 AND host_id BETWEEN 50 AND 95 LIMIT 1'
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: StartHost='50', EndHost='95', TotalPHPScripts='0'
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The PHP Script Server is Not Required
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT value FROM settings WHERE name = 'max_get_size''
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The Maximum SNMP OID Get Size is 60
04/22/2009 12:35:01 PM - SPINE: Poller[0] SPINE: Initializing Net-SNMP API
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: SNMP Header Version is 5.3.1
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: SNMP Library Version is 5.3.1
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT name, file, function FROM plugin_hooks WHERE status = 1 AND hook = 'config_arrays'"
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT name, file, function FROM plugin_hooks WHERE status = 1 AND hook = 'config_settings'"
04/22/2009 12:35:01 PM - SPINE: Poller[0] SPINE: Initializing PHP Script Server(s)
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT id FROM host WHERE disabled='' AND id BETWEEN 50 AND 95 ORDER BY id'
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: Initial Value of Active Threads is 0
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: Valid Thread to be Created
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: The Value of Active Threads is 1
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEBUG: In Poller, About to Start Polling of Host
04/22/2009 12:35:01 PM - CMDPHP: Poller[0] DEVEL: SQL Assoc: "SELECT name, file, function FROM plugin_hooks WHERE status = 1 AND hook = 'valid_host_fields'"
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT snmp_port, count(snmp_port) FROM poller_item WHERE host_id=0 AND rrd_next_step < 0 GROUP BY snmp_port'
04/22/2009 12:35:01 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT action, hostname, snmp_community, snmp_version, snmp_username, snmp_password, rrd_name, rrd_path, arg1, arg2, arg3, local_data_id, rrd_num, snmp_port, snmp_timeout, snmp_auth_protocol, snmp_priv_passphrase, snmp_priv_protocol, snmp_context FROM poller_item WHERE host_id=0 and rrd_next_step <=0 ORDER by snmp_port'

<removed lines>

04/22/2009 12:35:07 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT id, hostname, snmp_community, snmp_version, snmp_username, snmp_password, snmp_auth_protocol, snmp_priv_passphrase, snmp_priv_protocol, snmp_context, snmp_port, snmp_timeout, max_oids, availability_method, ping_method, ping_port, ping_timeout, ping_retries, status, status_event_count, status_fail_date, status_rec_date, status_last_error, min_time, max_time, cur_time, avg_time, total_polls, failed_polls, availability FROM host WHERE id=194'
<removed 1200 lines>
04/22/2009 12:35:10 PM - SPINE: Poller[0] Host[194] SNMP Result: Host did not respond to SNMP
04/22/2009 12:35:10 PM - SPINE: Poller[0] DEVDBG: SQL:'UPDATE host SET status='1', status_event_count='4', status_fail_date='2009-04-22 12:20:00', status_rec_date='2009-04-22 12:12:00', status_last_error='Host did not respond to SNMP', min_time='0.000000', max_time='0.000000', cur_time='0.000000', avg_time='0.000000', total_polls='1112', failed_polls='1109', availability='0.2698' WHERE id='194''
04/22/2009 12:35:10 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT snmp_port, count(snmp_port) FROM poller_item WHERE host_id=194 AND rrd_next_step < 0 GROUP BY snmp_port'
04/22/2009 12:35:10 PM - SPINE: Poller[0] DEVDBG: SQL:'SELECT action, hostname, snmp_community, snmp_version, snmp_username, snmp_password, rrd_name, rrd_path, arg1, arg2, arg3, local_data_id, rrd_num, snmp_port, snmp_timeout, snmp_auth_protocol, snmp_priv_passphrase, snmp_priv_protocol, snmp_context FROM poller_item WHERE host_id=194 and rrd_next_step <=0 ORDER by snmp_port'
04/22/2009 12:35:10 PM - SPINE: Poller[0] DEVDBG: SQL:'UPDATE poller_item SET rrd_next_step=rrd_next_step-300 WHERE host_id=194'
04/22/2009 12:35:10 PM - SPINE: Poller[0] DEVDBG: SQL:'UPDATE poller_item SET rrd_next_step=rrd_step-300 WHERE rrd_next_step < 0 and host_id=194'
04/22/2009 12:35:10 PM - SPINE: Poller[0] Host[194] NOTE: There are '12' Polling Items for this Host
04/22/2009 12:35:10 PM - SPINE: Poller[0] Host[194] DEBUG: HOST COMPLETE: About to Exit Host Polling Thread Function
04/22/2009 12:35:10 PM - SPINE: Poller[0] DEBUG: The Value of Active Threads is 0
04/22/2009 12:35:10 PM - SPINE: Poller[0] DEVDBG: SQL:'replace into settings (name,value) values ('date',NOW())'
User avatar
Howie
Cacti Guru User
Posts: 5508
Joined: Thu Sep 16, 2004 5:53 am
Location: United Kingdom
Contact:

Post by Howie »

Just had a quick try of this version along with my newly updated 0.8.7d install, and...

Code: Select all

04/22/2009 02:37:09 PM - SYSTEM STATS: Time:127.9749 Method:cmd.php Processes:4 Threads:N/A Hosts:237 HostsPerProcess:60 DataSources:11943 RRDsProcessed:4610
04/22/2009 02:45:00 PM - SYSTEM STATS: Time:298.8121 Method:spine Processes:4 Threads:15 Hosts:237 HostsPerProcess:60 DataSources:11943 RRDsProcessed:1071
04/22/2009 02:50:00 PM - SYSTEM STATS: Time:298.8212 Method:spine Processes:4 Threads:15 Hosts:237 HostsPerProcess:60 DataSources:11943 RRDsProcessed:2372
I'll hopefully have some time to work through the logs and see what is failing later.
Weathermap 0.98a is out! & QuickTree 1.0. Superlinks is over there now (and built-in to Cacti 1.x).
Some Other Cacti tweaks, including strip-graphs, icons and snmp/netflow stuff.
(Let me know if you have UK DevOps or Network Ops opportunities, too!)
User avatar
mahuani
Cacti User
Posts: 72
Joined: Tue Nov 01, 2005 2:10 pm
Location: Lafayette, LA
Contact:

Post by mahuani »

TheWitness, I have a ton of core dumps to play with now. Just let me know when you have time to take a look.
User avatar
gninja
Cacti User
Posts: 371
Joined: Tue Aug 24, 2004 5:02 pm
Location: San Francisco, CA
Contact:

Post by gninja »

I'm getting a "Bus Error (Spine thread)" with this, intermittently.

I can reproduce it on multiple hosts (at first I thought it was bad memory)..

It doesn't happen all the time, it seems to only happen on runs that include hosts from the end of my host id range, is reproducible with as few as one polled host; but it does not matter which host, as long as it's near the end of the host list.

Truss outputs:

Code: Select all

truss: get_struct 0x3900000000: Bad address
Running this gets the error, most of the time:

Code: Select all

/usr/local/spine/bin/spine --stdout --poller=2 --conf=/usr/local/spine/etc/spine.conf --verbosity=5 --first=1432 --last=1432
I can change 1432 to any number in the last 50 or so and get the error within the first few runs. I noticed that the output if it succeeds has the Hosts count as one higher than it should be (there's some logic in the code for excluding host id 0, which seems irrelevant here...) I tried chasing that down, but it does not seem to be related to this.

If you have advice on what to do next, I'm happy to persue this.
FreeBSD/RHEL
cacti-0.8.7i, spine 0.8.7i, PIA 3.1+boost 5.1
MySQL 5.5/InnoDB
RRDtool 1.2.27, PHP 5.1.6
User avatar
TheWitness
Developer
Posts: 17047
Joined: Tue May 14, 2002 5:08 pm
Location: MI, USA
Contact:

Post by TheWitness »

Sorry all. I have been in disposed. If you pull SVN, you will find the fix to this issue. Also, read the README. I have changed the default popen to nifty again due to timeout issues with standard popen.

I believe you will find SVN quite stable.

Regards,

Larry
True understanding begins only when we realize how little we truly understand...

Life is an adventure, let yours begin with Cacti!

Author of dozens of Cacti plugins and customization's. Advocate of LAMP, MariaDB, IBM Spectrum LSF and the world of batch. Creator of IBM Spectrum RTM, author of quite a bit of unpublished work and most of Cacti's bugs.
_________________
Official Cacti Documentation
GitHub Repository with Supported Plugins
Percona Device Packages (no support)
Interesting Device Packages


For those wondering, I'm still here, but lost in the shadows. Yearning for less bugs. Who want's a Cacti 1.3/2.0? Streams anyone?
User avatar
gninja
Cacti User
Posts: 371
Joined: Tue Aug 24, 2004 5:02 pm
Location: San Francisco, CA
Contact:

Post by gninja »

Awesome. SVN appears to solve my issues.
FreeBSD/RHEL
cacti-0.8.7i, spine 0.8.7i, PIA 3.1+boost 5.1
MySQL 5.5/InnoDB
RRDtool 1.2.27, PHP 5.1.6
Post Reply

Who is online

Users browsing this forum: No registered users and 0 guests