1.2.22 RRDfile is not created

[jmaris]

Hi,
I'm trying to set up Cacti 1.2.22 for 10sec polling interval.
I have created a new Data Source Profile in the Presets for this purpose, and I have duplicate-modified the data source and graph template to use this Data Profile.
I have modified the Data Query (SNMP - Interface Statistics) to reflect the 10sec polling in the Associated Graph Templates ("In/Out Bits - 10s").

I have checked the file permissions for the RRA directory and they are as expected (www-data:www-data).

When I create the graph, the data source is created, but the RRD file is not created. The [structured] directory for the device is correctly created.

I have run the Troubleshooting for Data Sources and this yields the following output:

Data Source Troubleshooter output.png (207.91 KiB) Viewed 2242 times

• I don't understand why it reports that the RRDfile Owner is root:root.

• Furthermore, the recommendations do not ring a bell either.

• It's also strange that the troubleshooting tool reports that the RRDfile existence has not yet been checked...

There is not much useful info in the Cacti log file, apart from the msg:
SNMPAGENT WARNING: SNMPAgent: Unable to find a poller

Code: Select all

2022-06-21 08:30:56 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:52 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:51 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:50 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:49 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:48 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:47 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:46 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:45 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:44 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:43 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:42 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:41 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:40 - AUTOM8 [PID: 103034] Not time to Run Discovery for 'Test Network'
2022-06-21 08:30:40 - SYSTEM DSSTATS STATS: Time:0.00 Type:HOURLY
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[103027] NOTE: Registering process! (dsstats, pmaster, 0, 103027)
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[103032] NOTE: Registering process! (spikekill, master, 0, 103032)
2022-06-21 08:30:40 - MAINT Cacti Log Rotation - TIMECHECK Ran: 2022-06-21 00:00:47, Now: 2022-06-21 08:30:40, Next: 2022-06-21 23:59:59
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[103029] NOTE: Registering process! (reports, master, 0, 103029)
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[103036] NOTE: Registering process! (maintenance, master, 1, 103036)
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q '/var/www/html/cacti/poller_maintenance.php']
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q '/var/www/html/cacti/poller_automation.php' -M]
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q '/var/www/html/cacti/poller_spikekill.php']
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_reports.php]
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_dsstats.php]
2022-06-21 08:30:40 - SYSTEM STATS: Time:0.4088 Method:spine Processes:1 Threads:1 Hosts:1 HostsPerProcess:1 DataSources:2 RRDsProcessed:0
2022-06-21 08:30:40 - SNMPAGENT WARNING: SNMPAgent: Unable to find a poller
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[102853] Maximum runtime of 58 seconds exceeded. Exiting.
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=10 --last=10 --mibs]
2022-06-21 08:30:40 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=0 --last=0 --mibs]
2022-06-21 08:30:39 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:38 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:37 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:36 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:35 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:34 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:33 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:32 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:31 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:30 - SYSTEM DSSTATS STATS: Time:0.00 Type:HOURLY
2022-06-21 08:30:30 - POLLER: Poller[Main Poller] PID[103014] NOTE: Registering process! (dsstats, pmaster, 0, 103014)
2022-06-21 08:30:30 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_dsstats.php]
2022-06-21 08:30:30 - SYSTEM STATS: Time:0.2893 Method:spine Processes:1 Threads:1 Hosts:1 HostsPerProcess:1 DataSources:2 RRDsProcessed:0
2022-06-21 08:30:30 - SNMPAGENT WARNING: SNMPAgent: Unable to find a poller
2022-06-21 08:30:30 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:30 - POLLER: Poller[Main Poller] PID[102853] Maximum runtime of 58 seconds exceeded. Exiting.
2022-06-21 08:30:30 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:30 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=10 --last=10 --mibs]
2022-06-21 08:30:30 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=0 --last=0 --mibs]
2022-06-21 08:30:29 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:28 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:27 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:26 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:25 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:24 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:23 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:22 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:21 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:20 - SYSTEM DSSTATS STATS: Time:0.00 Type:HOURLY
2022-06-21 08:30:20 - POLLER: Poller[Main Poller] PID[103001] NOTE: Registering process! (dsstats, pmaster, 0, 103001)
2022-06-21 08:30:20 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_dsstats.php]
2022-06-21 08:30:20 - SYSTEM STATS: Time:0.3045 Method:spine Processes:1 Threads:1 Hosts:1 HostsPerProcess:1 DataSources:2 RRDsProcessed:0
2022-06-21 08:30:20 - SNMPAGENT WARNING: SNMPAgent: Unable to find a poller
2022-06-21 08:30:20 - POLLER: Poller[Main Poller] PID[102853] Maximum runtime of 58 seconds exceeded. Exiting.
2022-06-21 08:30:20 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:20 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:20 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=10 --last=10 --mibs]
2022-06-21 08:30:20 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=0 --last=0 --mibs]
2022-06-21 08:30:19 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:18 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:17 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:16 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:15 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:15 - SYSTEM DSSTATS STATS: Time:0.00 Type:HOURLY
2022-06-21 08:30:15 - POLLER: Poller[Main Poller] PID[102987] NOTE: Registering process! (dsstats, pmaster, 0, 102987)
2022-06-21 08:30:14 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_dsstats.php]
2022-06-21 08:30:14 - SYSTEM STATS: Time:4.7601 Method:spine Processes:1 Threads:1 Hosts:1 HostsPerProcess:1 DataSources:2 RRDsProcessed:0
2022-06-21 08:30:14 - SNMPAGENT WARNING: SNMPAgent: Unable to find a poller
2022-06-21 08:30:14 - POLLER: Poller[Main Poller] PID[102853] Maximum runtime of 58 seconds exceeded. Exiting.
2022-06-21 08:30:14 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:14 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=10 --last=10 --mibs]
2022-06-21 08:30:14 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=0 --last=0 --mibs]
2022-06-21 08:30:14 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:07 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:06 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:05 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:04 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:03 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:02 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:01 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:00 - POLLER: Poller[Main Poller] PID[102966] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:00 - POLLER: Poller[Main Poller] PID[102966] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=10 --last=10 --mibs]
2022-06-21 08:30:00 - SYSTEM DSSTATS STATS: Time:0.00 Type:HOURLY
2022-06-21 08:30:00 - POLLER: Poller[Main Poller] PID[102968] NOTE: Registering process! (dsstats, pmaster, 0, 102968)
2022-06-21 08:30:00 - POLLER: Poller[Main Poller] PID[102966] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=0 --last=0 --mibs]
2022-06-21 08:30:00 - POLLER: Poller[Main Poller] PID[102966] NOTE: Poller Int: '10', Cron Int: '60', Time Since Last: '60.74', Max Runtime '58', Poller Runs: '6'
2022-06-21 08:30:00 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_dsstats.php]
2022-06-21 08:30:00 - SYSTEM STATS: Time:0.3469 Method:spine Processes:1 Threads:1 Hosts:1 HostsPerProcess:1 DataSources:2 RRDsProcessed:0
2022-06-21 08:30:00 - SNMPAGENT WARNING: SNMPAgent: Unable to find a poller
2022-06-21 08:30:00 - POLLER: Poller[Main Poller] PID[102853] Maximum runtime of 58 seconds exceeded. Exiting.
2022-06-21 08:30:00 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:30:00 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=10 --last=10 --mibs]
2022-06-21 08:30:00 - POLLER: Poller[Main Poller] PID[102853] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=0 --last=0 --mibs]
2022-06-21 08:29:59 - POLLER: Poller[Main Poller] PID[102853] WARNING: Cacti Polling Cycle Exceeded Poller Interval by 35.234876155853 seconds
2022-06-21 08:29:59 - SYSTEM STATS: Time:45.1924 Method:spine Processes:1 Threads:1 Hosts:1 HostsPerProcess:1 DataSources:2 RRDsProcessed:0
2022-06-21 08:29:59 - SNMPAGENT WARNING: SNMPAgent: Unable to find a poller
2022-06-21 08:29:59 - POLLER: Poller[Main Poller] PID[102853] Maximum runtime of 58 seconds exceeded. Exiting.
2022-06-21 08:29:59 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:59 - AUTOM8 [PID: 102943] Not time to Run Discovery for 'Test Network'
2022-06-21 08:29:59 - MAINT Cacti Log Rotation - TIMECHECK Ran: 2022-06-21 00:00:47, Now: 2022-06-21 08:29:59, Next: 2022-06-21 23:59:59
2022-06-21 08:29:59 - POLLER: Poller[Main Poller] PID[102945] NOTE: Registering process! (maintenance, master, 1, 102945)
2022-06-21 08:29:59 - POLLER: Poller[Main Poller] PID[102939] NOTE: Registering process! (reports, master, 0, 102939)
2022-06-21 08:29:59 - POLLER: Poller[Main Poller] PID[102941] NOTE: Registering process! (spikekill, master, 0, 102941)
2022-06-21 08:29:59 - SYSTEM DSSTATS STATS: Time:0.00 Type:HOURLY
2022-06-21 08:29:59 - POLLER: Poller[Main Poller] PID[102937] NOTE: Registering process! (dsstats, pmaster, 0, 102937)
2022-06-21 08:29:58 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q '/var/www/html/cacti/poller_maintenance.php']
2022-06-21 08:29:58 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q '/var/www/html/cacti/poller_automation.php' -M]
2022-06-21 08:29:58 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q '/var/www/html/cacti/poller_spikekill.php']
2022-06-21 08:29:58 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_reports.php]
2022-06-21 08:29:58 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_dsstats.php]
2022-06-21 08:29:58 - SYSTEM STATS: Time:0.3169 Method:spine Processes:1 Threads:1 Hosts:1 HostsPerProcess:1 DataSources:2 RRDsProcessed:0
2022-06-21 08:29:58 - SNMPAGENT WARNING: SNMPAgent: Unable to find a poller
2022-06-21 08:29:58 - POLLER: Poller[Main Poller] PID[102761] Maximum runtime of 58 seconds exceeded. Exiting.
2022-06-21 08:29:58 - POLLER: Poller[Main Poller] PID[102761] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:58 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:58 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=10 --last=10 --mibs]
2022-06-21 08:29:58 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=0 --last=0 --mibs]
2022-06-21 08:29:57 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:56 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:55 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:54 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:53 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:52 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:51 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:50 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:49 - SYSTEM DSSTATS STATS: Time:0.00 Type:HOURLY
2022-06-21 08:29:49 - POLLER: Poller[Main Poller] PID[102924] NOTE: Registering process! (dsstats, pmaster, 0, 102924)
2022-06-21 08:29:49 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_dsstats.php]
2022-06-21 08:29:49 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:48 - SYSTEM STATS: Time:0.5891 Method:spine Processes:1 Threads:1 Hosts:1 HostsPerProcess:1 DataSources:2 RRDsProcessed:0
2022-06-21 08:29:48 - SNMPAGENT WARNING: SNMPAgent: Unable to find a poller
2022-06-21 08:29:48 - POLLER: Poller[Main Poller] PID[102761] Maximum runtime of 58 seconds exceeded. Exiting.
2022-06-21 08:29:48 - POLLER: Poller[Main Poller] PID[102761] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:48 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=10 --last=10 --mibs]
2022-06-21 08:29:48 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=0 --last=0 --mibs]
2022-06-21 08:29:48 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:47 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:46 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:45 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:44 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:43 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:42 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:42 - SYSTEM DSSTATS STATS: Time:0.01 Type:HOURLY
2022-06-21 08:29:42 - POLLER: Poller[Main Poller] PID[102911] NOTE: Registering process! (dsstats, pmaster, 0, 102911)
2022-06-21 08:29:42 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_dsstats.php]
2022-06-21 08:29:41 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:40 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:39 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:38 - SYSTEM STATS: Time:0.4409 Method:spine Processes:1 Threads:1 Hosts:1 HostsPerProcess:1 DataSources:2 RRDsProcessed:0
2022-06-21 08:29:38 - SNMPAGENT WARNING: SNMPAgent: Unable to find a poller
2022-06-21 08:29:38 - POLLER: Poller[Main Poller] PID[102761] Maximum runtime of 58 seconds exceeded. Exiting.
2022-06-21 08:29:38 - POLLER: Poller[Main Poller] PID[102761] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:38 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=10 --last=10 --mibs]
2022-06-21 08:29:38 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:38 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/local/spine/bin/spine, ARGS: -C '/usr/local/spine/etc/spine.conf.dist' --poller=1 --first=0 --last=0 --mibs]
2022-06-21 08:29:37 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:36 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:35 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:34 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:33 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:32 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:31 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:30 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:29 - POLLER: Poller[Main Poller] PID[102853] Processing Poller Output with 40000 maximum items to be processed
2022-06-21 08:29:28 - SYSTEM DSSTATS STATS: Time:0.00 Type:HOURLY
2022-06-21 08:29:28 - POLLER: Poller[Main Poller] PID[102897] NOTE: Registering process! (dsstats, pmaster, 0, 102897)
2022-06-21 08:29:28 - POLLER: Poller[Main Poller] PID[102761] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q /var/www/html/cacti/poller_dsstats.php]
2022-06-21 08:29:28 - SYSTEM STATS: Time:0.2708 Method:spine Processes:1 Threads:1 Hosts:1 HostsPerProcess:1 DataSources:2 RRDsProcessed:0
2022-06-21 08:29:28 - SNMPAGENT WARNING: SNMPAgent: Unable to find a poller

I'm running out of ideas to troubleshoot this

Cacti 1.2.22
Debian 11
Apache Version Apache/2.4.53 (Debian)
PHP 7.4
MariaDB 10.5 (1:10.5.15-0+deb11u1)
RRDtool Version Configured: 1.7.2+
RRDtool Version Found: 1.7.2
Spine 1.2.21

Thanks!
Jan

[jmaris]

as an update to my post:

when I 'manually' and repeatedly (e.g. every +/-10s) run spine via the following command:
#runuser -u www-data -- /usr/local/spine/bin/spine -C /usr/local/spine/etc/spine.conf.dist --poller=1 --first=10 --last=10 --mibs

then, the RRD files are created and updated.
I then get the following output:

Code: Select all

root@SVR:/var/www/html/cacti/rra/10# runuser -u www-data -- /usr/local/spine/bin/spine -C /usr/local/spine/etc/spine.conf.dist --poller=1 --first=10 --last=10 --mibs
SPINE: Using spine config file [/usr/local/spine/etc/spine.conf.dist]
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The path_php_server variable is /var/www/html/cacti/script_server.php
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The path_cactilog variable is /var/www/html/cacti/log/cacti.log
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The version variable is 10.5.15-MariaDB-0+deb11u1
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The log_destination variable is 1 (FILE)
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The path_php variable is /usr/bin/php
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The availability_method variable is 2
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The ping_recovery_count variable is 3
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The ping_failure_count variable is 2
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The ping_method variable is 2
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The ping_retries variable is 1
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The ping_timeout variable is 400
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The snmp_retries variable is 3
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The log_perror variable is 0
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The log_pwarn variable is 0
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The boost_redirect variable is 0
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The boost_rrd_update_enable variable is 0
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The log_pstats variable is 0
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The threads variable is 1
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The polling interval is 10 seconds
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The number of concurrent processes is 2
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The script timeout is 25
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The selective_device_debug variable is
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The spine_log_level variable is 1
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The number of php script servers to run is 1
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The number of active data source profiles is 2
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The number of snmp ports on the system is 1
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: StartDevice='10', EndDevice='10', TotalPHPScripts='0'
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The PHP Script Server is Not Required
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: The Maximum SNMP OID Get Size is 10
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Total Connections made 1
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Creating Local Connection Pool of 1 threads.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Creating Local Connection 0.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Total Connections made 2
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Version 1.2.21 starting
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: MySQL is Thread Safe!
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Spine running as 33 UID, 33 EUID
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] WARNING: Spine NOT able to set effective UID to 0
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] WARNING: Spine NOT running as root.  This is required if using ICMP.  Please run "chown root:root spine;chmod u+s spine" to resolve.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Spine has not got ICMP
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Initializing Net-SNMP API
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Issues with SNMP Header Version information, assuming old version of Net-SNMP.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Initializing PHP Script Server(s)
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] Spine will support multithread device polling.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Initial Value of Available Threads is 1 (0 outstanding)
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Valid Thread to be Created (139631466473216)
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Available Threads is 0 (1 outstanding)
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Device[0] HT[1] In Poller, About to Start Polling
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Traversing Local Connection Pool for free connection.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Checking Local Pool ID 0.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Allocating Local Pool ID 0.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[0] HT[1] Updating Poller Items for Next Poll
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[0] HT[1] Total Time: 0.0024 Seconds
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Freeing Local Pool ID 0
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Device[0] HT[1] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Valid Thread to be Created (139631466473216)
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Device[10] HT[1] In Poller, About to Start Polling
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Available Threads is 0 (1 outstanding)
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631478194560] WARNING: Device[10] polling sleeping while waiting for 1 Threads to End
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Traversing Local Connection Pool for free connection.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Checking Local Pool ID 0.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Allocating Local Pool ID 0.
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] get_namebyhost(10.xx.xx.xx) - Allocating name_t
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] get_namebyhost(10.xx.xx.xx) - No delimiter, assume full hostname
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] INFO: SNMP Device '10.xx.xx.xx:161' has a timeout of 500000 (500), with 3 retries
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] DEBUG: Entering SNMP Ping
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] SNMP Result: Device responded to SNMP
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] Checking for System Information Update
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] Updating Full System Information Table
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Device[10] HT[1] RECACHE: Processing 1 items in the auto reindex cache for '10.xx.xx.xx'
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] HT[1] DQ[4] Extended Uptime Result: 24521962, Is Numeric: 1
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] HT[1] DQ[4] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 2445970400 < output: 2452196200)
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] HT[1] NOTE: There are '2' Polling Items for this Device
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] INFO: SNMP Device '10.xx.xx.xx:161' has a timeout of 500000 (500), with 3 retries
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] HT[1] DS[23] TT[2.93] SNMP: v2: 10.xx.xx.xx, dsname: traffic_in_hd, oid: .1.3.6.1.2.1.2.2.1.10.8, value: 3328069610
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] HT[1] DS[23] TT[3.07] SNMP: v2: 10.xx.xx.xx, dsname: traffic_out_hd, oid: .1.3.6.1.2.1.2.2.1.16.8, value: 1658635297
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Setting up writes to local database
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] HT[1] Updating Poller Items for Next Poll
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] Device[10] HT[1] Total Time: 0.2 Seconds
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Freeing Local Pool ID 0
2022-06-22 09:34:19 - SPINE: Poller[1] PID[2261] PT[139631466473216] DEBUG: Device[10] HT[1] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
2022-06-22 09:34:20 - SPINE: Poller[1] PID[2261] PT[139631478194560] The final count of Threads is 0
2022-06-22 09:34:20 - SPINE: Poller[1] PID[2261] PT[139631478194560] INFO: Thread complete for Device[0] and 0 to 0 sources
2022-06-22 09:34:20 - SPINE: Poller[1] PID[2261] PT[139631478194560] INFO: Thread complete for Device[10] and 0 to 0 sources
2022-06-22 09:34:20 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Closing Local Connection Pool ID 0
2022-06-22 09:34:20 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Thread Cleanup Complete
2022-06-22 09:34:20 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: PHP Script Server Pipes Closed
2022-06-22 09:34:20 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Allocated Variable Memory Freed
2022-06-22 09:34:20 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: MYSQL Free & Close Completed
2022-06-22 09:34:20 - SPINE: Poller[1] PID[2261] PT[139631478194560] DEBUG: Net-SNMP Close Completed
2022-06-22 09:34:20 - SPINE: Poller[1] PID[2261] PT[139631478194560] Time: 1.3932 s, Threads: 1, Devices: 2

The Cacti daemon is definitely running:

Code: Select all

root@SVR:/var/www/html/cacti/rra/10# sudo systemctl status cactid.service
● cactid.service - Cacti Daemon Main Poller Service
     Loaded: loaded (/etc/systemd/system/cactid.service; enabled; vendor preset: enabled)
     Active: active (running) since Wed 2022-06-22 09:15:17 UTC; 26min ago
    Process: 506 ExecStart=/var/www/html/cacti/cactid.php (code=exited, status=0/SUCCESS)
   Main PID: 947 (php)
      Tasks: 5 (limit: 4678)
     Memory: 73.7M
        CPU: 42.697s
     CGroup: /system.slice/cactid.service
             ├─ 947 php /var/www/html/cacti/cactid.php
             ├─2591 /usr/bin/php -q /var/www/html/cacti/poller.php --force
             ├─2639 /usr/bin/php -q /var/www/html/cacti/poller.php --force
             ├─2650 sh -c /usr/bin/rrdtool -
             └─2651 /usr/bin/rrdtool -

Jun 22 09:32:00 SVR cactid.php[947]: Total[957.4090] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS:  -q /var/www/html/cacti/poller.php --force]
Jun 22 09:33:00 SVR cactid.php[947]: Total[1017.7382] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS:  -q /var/www/html/cacti/poller.php --force]
Jun 22 09:34:00 SVR cactid.php[947]: Total[1078.1048] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS:  -q /var/www/html/cacti/poller.php --force]
Jun 22 09:35:00 SVR cactid.php[947]: Total[1137.5284] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS:  -q /var/www/html/cacti/poller.php --force]
Jun 22 09:36:00 SVR cactid.php[947]: Total[1197.6310] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS:  -q /var/www/html/cacti/poller.php --force]
Jun 22 09:37:00 SVR cactid.php[947]: Total[1257.7638] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS:  -q /var/www/html/cacti/poller.php --force]
Jun 22 09:38:00 SVR cactid.php[947]: Total[1317.9347] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS:  -q /var/www/html/cacti/poller.php --force]
Jun 22 09:39:00 SVR cactid.php[947]: Total[1378.0197] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS:  -q /var/www/html/cacti/poller.php --force]
Jun 22 09:40:00 SVR cactid.php[947]: Total[1437.8073] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS:  -q /var/www/html/cacti/poller.php --force]
Jun 22 09:41:00 BE-SVR-254-023 cactid.php[947]: Total[1498.0182] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS:  -q /var/www/html/cacti/poller.php --force]

Any reason why the spine process might not be run automatically from the poller process(es)?

Thanks
Jan

[TheWitness]

I would chown -R www-data rra

[TheWitness]

What's the user in the systems unit file.. Maybe it's a bad user like Apache?

[jmaris]

hi,

the rra directory is already owned by www-data:

Code: Select all

drwxr-xr-x 4 www-data www-data   4096 Jun 21 07:36 rra

The user in the systems unit file also seems to be correct

Code: Select all

/etc/systemd/system$ cat cactid.service

[Unit]
Description=Cacti Daemon Main Poller Service
After=network.target

[Service]
Type=forking
User=www-data
Group=www-data
EnvironmentFile=/etc/default/cactid
ExecStart=/var/www/html/cacti/cactid.php
Restart=always
RestartSec=5s

[Install]
WantedBy=multi-user.target

Is there perhaps something else I'm missing?
Thanks

[TheWitness]

Is cactid running?

[jmaris]

Yes, see my Wednesday post showing the output of the cmd: root@SVR:/var/www/html/cacti/rra/10# sudo systemctl status cactid.service
--> Active: active (running)

Thanks,
Jan

[jmaris]

another question: - if cactid is running, is it still needed to have a cron job, as it used to be before cactid was introduced?

Thanks, Jan

[TheWitness]

No.

[jmaris]

does anyone have any other suggestions to troubleshoot this?

[jmaris]

I have debugged this a bit deeper and found some strange behaviour with respect to cactid daemon and spine.
I managed to get the system working via the suggested debug (/var/www/html/cacti/service/README.md) to run the daemon in foreground with the debug option enabled.

Code: Select all

./cactid.php –-foreground –-debug

I then had the impression that cactid and poller.php did what they're supposed to do, but spine was not "activated"...
I then only got spine working if I commented out the Cacti_Log line in the spine conf file.

Code: Select all

#Cacti_Log     /var/www/html/cacti/log/cacti.log

With this spine config, I retried to run cactid.php from systemctl, but that again resulted in spine not doing what it's supposed to do.

So I currently have a workaround to initiate cactid.php in foreground (without the debug) and deamonise it by adding the ampersand:

Code: Select all

./cactid.php &

Jan

[jmaris]

Hi,
I spent a bit more time on trying to solve this issue.
I have now upgraded to spine 1.2.23, but it seems that spine produces a Segmentation fault:

Code: Select all

root@server:/usr/local/spine/bin# gdb spine
GNU gdb (Debian 10.1-1.7) 10.1.90.20210103-git
Copyright (C) 2021 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from spine...
(gdb) run -R -C /usr/local/spine/etc/spine.conf.dist
Starting program: /usr/local/spine/bin/spine -R -C /usr/local/spine/etc/spine.conf.dist
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
SPINE: Using spine config file [/usr/local/spine/etc/spine.conf.dist]

Program received signal SIGSEGV, Segmentation fault.
0x000055568946f030 in spine_log (format=format@entry=0x555689483800 "LOCKS: [START] Mutex lock for %s") at util.c:1255
1255            va_start(args, format);
(gdb) where
#0  0x000055568946f030 in spine_log (format=format@entry=0x555689483800 "LOCKS: [START] Mutex lock for %s") at util.c:1255
#1  0x0000555689474f76 in thread_mutex_lock (mutex=mutex@entry=5) at locks.c:235
#2  0x000055568946f34a in spine_log (format=format@entry=0x555689483800 "LOCKS: [START] Mutex lock for %s") at util.c:1316
#3  0x0000555689474f76 in thread_mutex_lock (mutex=mutex@entry=5) at locks.c:235
#4  0x000055568946f34a in spine_log (format=format@entry=0x555689483800 "LOCKS: [START] Mutex lock for %s") at util.c:1316
#5  0x0000555689474f76 in thread_mutex_lock (mutex=mutex@entry=5) at locks.c:235
#6  0x000055568946f34a in spine_log (format=format@entry=0x555689483800 "LOCKS: [START] Mutex lock for %s") at util.c:1316
#7  0x0000555689474f76 in thread_mutex_lock (mutex=mutex@entry=5) at locks.c:235
#8  0x000055568946f34a in spine_log (format=format@entry=0x555689483800 "LOCKS: [START] Mutex lock for %s") at util.c:1316
#9  0x0000555689474f76 in thread_mutex_lock (mutex=mutex@entry=5) at locks.c:235
#10 0x000055568946f34a in spine_log (format=format@entry=0x555689483800 "LOCKS: [START] Mutex lock for %s") at util.c:1316
#11 0x0000555689474f76 in thread_mutex_lock (mutex=mutex@entry=5) at locks.c:235
#12 0x000055568946f34a in spine_log (format=format@entry=0x55568947f81b "DEVDBG: SQL:%s") at util.c:1316
#13 0x000055568946d988 in db_query (mysql=mysql@entry=0x7ffdad89d030, type=type@entry=0, query=query@entry=0x7ffdad89c8e0 "SELECT value FROM settings WHERE name = 'path_webroot'") at sql.c:156
#14 0x000055568946e854 in getsetting (psql=psql@entry=0x7ffdad89d030, setting=setting@entry=0x5556894826e7 "path_webroot", mode=0) at util.c:100
#15 0x0000555689471919 in read_config_options () at util.c:385
#16 0x000055568946bf88 in main (argc=<optimized out>, argv=<optimized out>) at spine.c:492
(gdb) list
1250            char flogmessage[LOGSIZE];     /* Formatted Log Message */
1251            char stdoutmessage[LRG_LOGSIZE];   /* Message for stdout */
1252
1253            double cur_time;
1254
1255            va_start(args, format);
1256            vsnprintf(ulogmessage, LOGSIZE - 1, format, args);
1257            va_end(args);
1258
1259            /* default for "console" messages to go to stdout */
(gdb)

Any suggestions to have this resolved?

Kind regards, Jan.

[Osiris]

Are you running boost? Is so, update poller_boost.php and lib/boost.php from the 1.2.x branch if not. I'm not too sure.

You should report that default to GitHub.

[jmaris]

Hi,
no, I'm not using boost (should I?).
I will raise this then also on Github.

Kind regards, Jan

[TheWitness]

Yes, but before you enable, download lib/boost.php and poller_boost.php from the 1.2.x branch. If you are using Remote Data Collectors, boost is mandatory. Lastly, make sure the poller_output table is using the MEMORY storage engine.