Poller getting correct values but rrdtool is writing U

[m0j0]

I've got a new build (1.1.38) running on Ubuntu 18.04 with rrdtool v1.7.0.

I've created 11 new graphs all for localhost - the standard Memory Usage, Load Average, Logged In Users, and Processes as well as disk space graphs for my mounted volumes. All but the Load Average graph are showing NaN values. I can see that the rrd files are being written to every 5 minutes but there's no meaningful data being written. I set the logging to debug and can see the poller is getting correct values for everything but when it comes to the CACTI2RRD process, only "U" values are being written. There's nothing in the poller-error.log or the rrd.log at all that indicates what might be happening.

Here's an example of what I'm seeing in the cacti.log:

Code: Select all

2018/08/22 12:35:01 - POLLER: Poller[1] Device[1] DS[3] CMD: perl /usr/share/cacti/site/scripts/loadavg_multi.pl, output: 1min:0.00 5min:0.03 10min:0.00
....
2018/08/22 12:35:01 - POLLER: Poller[1] Device[1] DS[20] CMD: perl /usr/share/cacti/site/scripts/query_unix_partitions.pl 'get' 'available' '/dev/mapper/pvr--vg-Recordings', output: 366150232
2018/08/22 12:35:01 - POLLER: Poller[1] Device[1] DS[20] CMD: perl /usr/share/cacti/site/scripts/query_unix_partitions.pl 'get' 'used' '/dev/mapper/pvr--vg-Recordings', output: 157881768
....
2018/08/22 12:35:01 - POLLER: Poller[1] Time: 0.2274 s, Poller: , Theads: N/A, Devices: 1
2018/08/22 12:35:02 - POLLER: Poller[1] Parsed MULTI output field '1min:0.00' [map 1min->load_1min]
2018/08/22 12:35:02 - POLLER: Poller[1] Parsed MULTI output field '5min:0.03' [map 5min->load_5min]
2018/08/22 12:35:02 - POLLER: Poller[1] Parsed MULTI output field '10min:0.00' [map 10min->load_15min]
....
2018/08/22 12:35:02 - POLLER: Poller[1] CACTI2RRD: /usr/bin/rrdtool update /usr/share/cacti/site/rra/pvr_load_1min_3.rrd --template load_1min:load_5min:load_15min 1534905301:0.00:0.03:0.00
....
2018/08/22 12:35:02 - POLLER: Poller[1] CACTI2RRD: /usr/bin/rrdtool update /usr/share/cacti/site/rra/pvr_hdd_free_20.rrd --template hdd_used:hdd_free 1534905301:U:U
....
2018/08/22 12:35:02 - SYSTEM STATS: Time:1.2384 Method:cmd.php Processes:1 Threads:N/A Hosts:1 HostsPerProcess:1 DataSources:19 RRDsProcessed:12

As can be seen above, the poller gets values for available and used but writes U:U to the rrd, but no indication as to why. I've tried deleting all the graphs and recreating them from scratch but I got the same result.

[netniV]

OK, so what you need to do is make sure that your SNMP daemon is actually allowing you to pull the data out. By default, Linux actually locks down most information to only work over 127.0.0.1 (and sometimes not even then). Check the 'snmpd.conf' file usually located in /etc/snmp/

[m0j0]

SNMP seems to be working fine, the poller is getting the values out correctly but those values are not being written into the rrd files. I've since created another graph from a remote host (SNMP based interface graph) and that works fine.

Based on further reading I've done, I suspect it may be due to issues with php 7.2 and Cacti 1.1.x. I'd already manually fixed up this issue - https://github.com/Cacti/cacti/issues/1546. This is just a wild guess but I'll see if I can try php 7.1 and see what happens.

[netniV]

Yeah stick with 7.1 for Cacti Core 1.1.

7.2 has been tested for Cacti Core 1.2 (I'm using it) but we aren't quite ready for beta yet.

[m0j0]

Interestingly, I just updated PHP from 7.2.7 to 7.2.9 and now all is working and all of my graphs have data. I'll keep it as is for now unless I have issues with new graphs. Otherwise, I'll revert to 7.1.

[netniV]

Can't see why that would be... but if it works for you

[m0j0]

Everything has been running fine since that last update. Today I applied some package updates, one of which was php7.2.10. After applying this update, I was back in the same situation. I bit the bullet and installed php 7.1, switched over to 7.1 via "a2dismod php7.2 && a2enmod php7.1" and changed the /usr/bin/php symlink to point to 7.1. Verified both command line and web server are on php 7.1. I even gave the system a full reboot just to be sure.

I'm still getting the same issue and it's the same graphs that are getting "U" written to instead of the value received from the poll, so now I'm out of ideas. As an example, here are some values retrieved for load, memory, logged in users and processes on the local device:

Code: Select all

19/09/2018 10:30:02 - POLLER: Poller[1] Device[1] DS[3] CMD: perl /usr/share/cacti/site/scripts/loadavg_multi.pl, output: 1min:0.72 5min:0.94 10min:0.74
19/09/2018 10:30:02 - POLLER: Poller[1] Device[1] DS[13] CMD: perl /usr/share/cacti/site/scripts/linux_memory.pl 'MemFree:', output: 123580
19/09/2018 10:30:02 - POLLER: Poller[1] Device[1] DS[14] CMD: perl /usr/share/cacti/site/scripts/linux_memory.pl 'SwapFree:', output: 1003516
19/09/2018 10:30:02 - POLLER: Poller[1] Device[1] DS[15] CMD: perl /usr/share/cacti/site/scripts/unix_users.pl '', output: 1
19/09/2018 10:30:02 - POLLER: Poller[1] Device[1] DS[16] CMD: perl /usr/share/cacti/site/scripts/unix_processes.pl, output: 346

And here's what's written to the rrd files:

Code: Select all

19/09/2018 10:30:03 - POLLER: Poller[1] CACTI2RRD: /usr/bin/rrdtool update /usr/share/cacti/site/rra/pvr_load_1min_3.rrd --template load_1min:load_5min:load_15min 1537317002:0.72:0.94:0.74
19/09/2018 10:30:03 - POLLER: Poller[1] CACTI2RRD: /usr/bin/rrdtool update /usr/share/cacti/site/rra/pvr_mem_buffers_13.rrd --template mem_buffers 1537317002:U
19/09/2018 10:30:03 - POLLER: Poller[1] CACTI2RRD: /usr/bin/rrdtool update /usr/share/cacti/site/rra/pvr_mem_swap_14.rrd --template mem_swap 1537317002:U
19/09/2018 10:30:03 - POLLER: Poller[1] CACTI2RRD: /usr/bin/rrdtool update /usr/share/cacti/site/rra/pvr_users_15.rrd --template users 1537317002:U
19/09/2018 10:30:03 - POLLER: Poller[1] CACTI2RRD: /usr/bin/rrdtool update /usr/share/cacti/site/rra/pvr_proc_16.rrd --template proc 1537317002:U

Only the "load" rrd is being populated correctly whereas all the others are getting "U" instead. I've got my logging set to debug level and this is the extent of the information I'm getting. There's nothing in the poller-error.log or the rrd.log file at all. Also nothing in my php error log. Something seems to be going wrong between getting the values and writing the rrd but I've got no idea where to look. I've only got one other device/graph configured and that's an interface utilization graph for a remote firewall via SNMP - this has never had any problems throughout all of this.

[m0j0]

Everything has been running fine since that last update.

Scratch that. Was just looking at older graph data and noticed a period of approximately 38 hours last week where it was happening and then just magically righted itself. I don't recall doing anything at the time on this server. I just wish I could get more information to see why the value is changing from something valid to an Unknown.

Graph showing 38 hours of Unknown values

cacti_graph_12.png (36.09 KiB) Viewed 1396 times

[m0j0]

I've found a solution after discovering the following entries in my logs when the poller is run:

20/09/2018 13:20:02 - PCOMMAND Device[1] WARNING: Recache Event Detected for Device
20/09/2018 13:20:03 - RECACHE STATS: Poller: RecacheTime:0.3839 DevicesRecached:1

Looking at historical logs, I could see the gaps in the graphs corresponded with these entries. Looking around I found someone with the same log entries albeit for a completely different symptom. The post included a workaround of disabling the re-index method in the associated data query (Unix - Get Mounted Partitions) for that device so I tried that and it fixed my issue and now all my graphs are working.

However, what are the implications of the changes of made? I can't think of any given it's a fairly static system. Also, why would this have been causing an issue with graphs not associated to that data query (ie memory usage graph) but not to the load graph?