very different behavior from cmd.php to spine

[leonardo_gyn]

Hello Guys ... i'm running cacti 1.2.14 on a CentOS 8 box and, with cmd.php as the poller, everything works just fine. I'm doing some basic monitoring of a few linux boxes, nothing fancy, interfaces and some Host MIB graphs. MySQL is Community Version, 8.0.21. Cacti boost is disabled. Single local poller, no remote pollers at all.

I have also compiled spine (1.2.14, matching version to cacti) and, when trying to use it, i'm getting some crazy results ... it's kind of working, some graphs are working just fine on spine, but most of script queries/scripts data sources stop working completly. I have already searched forums and Google and tried several things:

1) MySQL max connections is appropriate
2) logs and RRD files seems to have appropriate permission because, as I told, some graphs just keep working fine. Logs are being written by spine successfully as well
3) have tried SUID the spine binary, as found on spine error message when running from cli without SUID, but that didn't changed anything

From the cacti.log files, I can see that when using cmd.php, the RRDsProcessed number matches exactly the number of "Data Sources" I have. The actual "DataSources" number is higher because I believe some RRDs have more than one information, just like traffic ones have in and out data. However, 148 matches exactly my data source count from the Web UI, which is basically the number of RRD files. Everything OK.

As soon as I change to spine, RRDsProcessed drops from 148 to 80, and I start getting some "poller output table not empty" warnings, however I simply cannot find what's causing that. I'm running log level on MEDIUM, have tried HIGH, but couldn't find anything that could help.

Code: Select all

[root@firewall log]# tail -f cacti.log | egrep -i '(SYSTEM STATS: Time|empty)'
06/Oct/2020 11:06:24 - SYSTEM STATS: Time:82.7348 Method:cmd.php Processes:6 Threads:0 Hosts:14 HostsPerProcess:3 DataSources:206 RRDsProcessed:148
06/Oct/2020 11:11:25 - SYSTEM STATS: Time:82.7319 Method:cmd.php Processes:6 Threads:0 Hosts:14 HostsPerProcess:3 DataSources:206 RRDsProcessed:148
(changed poller to spine, all the rest is kept unchanged)
06/Oct/2020 11:15:30 - SYSTEM STATS: Time:28.7387 Method:spine Processes:6 Threads:16 Hosts:14 HostsPerProcess:3 DataSources:206 RRDsProcessed:80
06/Oct/2020 11:20:02 - POLLER: Poller[1] WARNING: Poller Output Table not Empty.  Issues: 8, DS[3110, 3113, 3114, 3117, 3122, 3125, 3156, 3159]
06/Oct/2020 11:20:31 - SYSTEM STATS: Time:28.6560 Method:spine Processes:6 Threads:16 Hosts:14 HostsPerProcess:3 DataSources:206 RRDsProcessed:81
06/Oct/2020 11:25:01 - POLLER: Poller[1] WARNING: Poller Output Table not Empty.  Issues: 10, DS[3106, 3109, 3110, 3113, 3114, 3117, 3122, 3125, 3156, 3159]
06/Oct/2020 11:30:02 - POLLER: Poller[1] WARNING: Poller Output Table not Empty.  Issues: 9, DS[3110, 3113, 3114, 3117, 3122, 3125, 3129, 3156, 3159]
06/Oct/2020 11:30:30 - SYSTEM STATS: Time:28.6543 Method:spine Processes:6 Threads:16 Hosts:14 HostsPerProcess:3 DataSources:206 RRDsProcessed:82

poller_output MySQL table is basically populated with traffic_out values, that might indicate something ... table is getting flushed between runs however, I can see that because 'time' values are always from last run and are not getting accumulated there

Code: Select all

mysql> select * from poller_output;
+---------------+-------------+---------------------+-----------+
| local_data_id | rrd_name    | time                | output    |
+---------------+-------------+---------------------+-----------+
|          3110 | traffic_out | 2020-10-06 11:25:01 | 187044682 |
|          3113 | traffic_out | 2020-10-06 11:25:01 | 5442512   |
|          3114 | traffic_out | 2020-10-06 11:25:01 | 536826197 |
|          3117 | traffic_out | 2020-10-06 11:25:01 | 10807572  |
|          3122 | traffic_out | 2020-10-06 11:25:01 | 238920335 |
|          3125 | traffic_out | 2020-10-06 11:25:01 | 5464841   |
|          3129 | traffic_out | 2020-10-06 11:25:04 | 1519394   |
|          3156 | traffic_out | 2020-10-06 11:25:01 | 246043252 |
|          3159 | traffic_out | 2020-10-06 11:25:01 | 5407670   |
+---------------+-------------+---------------------+-----------+
9 rows in set (0.00 sec)

Other data sources, which are simply script ones, that works flawlessly with cmd.php, simply stop being called at all. They simply vanished from the logs. Example:

Code: Select all

06/Oct/2020 11:05:27 - POLLER: Poller[1] Device[88] DS[2954] CMD: /var/www/html/admin/cacti/scripts/ping_latency.pl '177.x.x.x' '50', output: roundtrip:8 packetloss:0
06/Oct/2020 11:10:28 - POLLER: Poller[1] Device[88] DS[2954] CMD: /var/www/html/admin/cacti/scripts/ping_latency.pl '177.x.x.x' '50', output: roundtrip:11 packetloss:0
(changed to spine at 11:12, and data source 2954 is gone from the logs)

and of course, as soon I change back to cmd.php, RRDsProcessed gets back to its normal:

Code: Select all

06/Oct/2020 11:36:23 - SYSTEM STATS: Time:80.7232 Method:cmd.php Processes:6 Threads:0 Hosts:14 HostsPerProcess:3 DataSources:206 RRDsProcessed:148

I have already used cacti/spine on older versions and never had similar problems, I'm really out of ideas here and would love some ideas from you guys THanks!

[Achea9]

Hi,
I also had almost the same issue and I upgraded to 1.2.14 and still some thing was strange. I just empty all the files in the rra/ Folder and deleted all Graphs and deleted all data sources and rebuild every thing new. It seems I see some Progress. May if you also do not have lots of Graphs, you may try to do the same.
Good Luck

cheers

[leonardo_gyn]

Hi,
I also had almost the same issue and I upgraded to 1.2.14 and still some thing was strange. I just empty all the files in the rra/ Folder and deleted all Graphs and deleted all data sources and rebuild every thing new. It seems I see some Progress. May if you also do not have lots of Graphs, you may try to do the same.
Good Luck

cheers

Have already tried that, but can't get consistent results with spine. Thanks for the suggestion anyway