Selective Device Debug does not work with Remote Data Collectors

[gj00354347]

Describe the bug

Hi Team ,

in fact one of my device was not getting populated in cacti 1.2.18 in a multi poller environment . So I thought of lets see what do we get in spine debug as we are using spine and thought of running the spine in verbose mode ie -V=5 that is debug .

But to my surprise i do not see any polling for that device . yes the spine is 1.2.17 as it is evident in the below mentioned logs of spine run as well .

./spine -f=323 -l=323 -R -S -V=5
SPINE: Using spine config file [spine.conf]
Total[0.0068] DEBUG: The path_php_server variable is //cacti/script_server.php
Total[0.0068] DEBUG: The path_cactilog variable is /opt/SP/cacti/log/cacti.log
Total[0.0068] DEBUG: The log_destination variable is 4 (STDOUT)
Total[0.0071] DEBUG: The path_php variable is /bin/php
Total[0.0073] DEBUG: The availability_method variable is 2
Total[0.0074] DEBUG: The ping_recovery_count variable is 3
Total[0.0075] DEBUG: The ping_failure_count variable is 2
Total[0.0077] DEBUG: The ping_method variable is 2
Total[0.0078] DEBUG: The ping_retries variable is 3
Total[0.0080] DEBUG: The ping_timeout variable is 500
Total[0.0081] DEBUG: The snmp_retries variable is 3
Total[0.0083] DEBUG: The log_perror variable is 1
Total[0.0084] DEBUG: The log_pwarn variable is 1
Total[0.0085] DEBUG: The boost_redirect variable is 1
Total[0.0087] DEBUG: The boost_rrd_update_enable variable is 1
Total[0.0089] DEBUG: The log_pstats variable is 1
Total[0.0091] DEBUG: The threads variable is 10
Total[0.0092] DEBUG: The polling interval is 300 seconds
Total[0.0094] DEBUG: The number of concurrent processes is 5
Total[0.0095] DEBUG: The script timeout is 60
Total[0.0096] DEBUG: The selective_device_debug variable is
Total[0.0098] DEBUG: The spine_log_level variable is 1
Total[0.0099] DEBUG: The number of php script servers to run is 1
Total[0.0105] DEBUG: StartDevice='323', EndDevice='323', TotalPHPScripts='1'
Total[0.0106] DEBUG: The PHP Script Server is Required
Total[0.0107] DEBUG: The Maximum SNMP OID Get Size is 10
Total[0.0112] DEBUG: Total Connections made 1
Total[0.0112] DEBUG: Creating Local Connection Pool of 10 threads.
Total[0.0112] DEBUG: Creating Local Connection 0.
Total[0.0116] DEBUG: Total Connections made 2
Total[0.0117] DEBUG: Creating Local Connection 1.
Total[0.0121] DEBUG: Total Connections made 3
Total[0.0121] DEBUG: Creating Local Connection 2.
Total[0.0124] DEBUG: Total Connections made 4
Total[0.0124] DEBUG: Creating Local Connection 3.
Total[0.0128] DEBUG: Total Connections made 5
Total[0.0128] DEBUG: Creating Local Connection 4.
Total[0.0133] DEBUG: Total Connections made 6
Total[0.0133] DEBUG: Creating Local Connection 5.
Total[0.0137] DEBUG: Total Connections made 7
Total[0.0137] DEBUG: Creating Local Connection 6.
Total[0.0142] DEBUG: Total Connections made 8
Total[0.0143] DEBUG: Creating Local Connection 7.
Total[0.0146] DEBUG: Total Connections made 9
Total[0.0147] DEBUG: Creating Local Connection 8.
Total[0.0152] DEBUG: Total Connections made 10
Total[0.0152] DEBUG: Creating Local Connection 9.
Total[0.0155] DEBUG: Total Connections made 11
Total[0.0156] DEBUG: Version 1.2.17 starting
Total[0.0156] DEBUG: MySQL is Thread Safe!
Total[0.0156] DEBUG: Capability CAP_NET_RAW is set.
Total[0.0156] DEBUG: Spine has cap_net_raw capability.
Total[0.0156] DEBUG: Spine has got ICMP
Total[0.0156] DEBUG: Initializing Net-SNMP API
Total[0.0156] DEBUG: Issues with SNMP Header Version information, assuming old version of Net-SNMP.
Total[0.0204] DEBUG: Initializing PHP Script Server(s)

Total[0.0204] DEBUG: SS[0] PHP Script Server Routine Starting
Total[0.0204] DEBUG: SS[0] PHP Script Server About to FORK Child Process
Total[0.0207] DEBUG: SS[0] PHP Script Server Child FORK Success
Total[0.2498] DEBUG: SS[0] Confirmed PHP Script Server running using readfd[17], writefd[16]
Total[0.2512] Spine will support multithread device polling.
Total[0.2516] DEBUG: Initial Value of Active Threads is 0
Total[0.2520] DEBUG: Valid Thread to be Created
Total[0.2521] DEBUG: In Poller, About to Start Polling of Device for Device ID 0
Total[0.2521] DEBUG: Traversing Local Connection Pool for free connection.
Total[0.2522] DEBUG: Checking Local Pool ID 0.
Total[0.2522] DEBUG: Allocating Local Pool ID 0.
Total[0.2522] Active Threads is 1, Pending is 1
Total[0.2535] Device[0] HT[1] Total Time: 0.0014 Seconds
Total[0.2539] DEBUG: Freeing Local Pool ID 0
Total[0.2539] DEBUG: Device[0] HT[1] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
Total[0.2539] DEBUG: The Value of Active Threads is 0 for Device ID 0
Total[0.2539] Active Threads is 0, Pending is 0
Total[0.3523] The Final Value of Threads is 0
Total[0.3524] DEBUG: Closing Local Connection Pool ID 0
Total[0.3524] DEBUG: Closing Local Connection Pool ID 1
Total[0.3525] DEBUG: Closing Local Connection Pool ID 2
Total[0.3526] DEBUG: Closing Local Connection Pool ID 3
Total[0.3526] DEBUG: Closing Local Connection Pool ID 4
Total[0.3526] DEBUG: Closing Local Connection Pool ID 5
Total[0.3527] DEBUG: Closing Local Connection Pool ID 6
Total[0.3527] DEBUG: Closing Local Connection Pool ID 7
Total[0.3527] DEBUG: Closing Local Connection Pool ID 8
Total[0.3528] DEBUG: Closing Local Connection Pool ID 9
Total[0.3528] DEBUG: Thread Cleanup Complete
Total[0.3528] DEBUG: SS[0] Script Server Shutdown Started
Total[0.4030] DEBUG: PHP Script Server Pipes Closed
Total[0.4030] DEBUG: Allocated Variable Memory Freed
Total[0.4030] DEBUG: MYSQL Free & Close Completed
Total[0.4032] DEBUG: Net-SNMP Close Completed
Total[0.4032] Time: 0.3523 s, Threads: 10, Devices: 1

so my first question is why spine is not in debug mode like polling for this OID and this is value , this OID and that is value but very often I do not see that , so is there any problem with code or what ??

now I enabled the device debug for id=323 but i do not see in the logs for this device , in fact any log .

user@cacti-remote-poller:/log $ grep -i 'device[323]' cacti.log
user@cacti-remote-poller:/log $

so I know it is a multi poller environment , so yes , i checked for logs on remote poller and yes I checked like whether the device is in debug mode on that poller or not so , i checked in web gui of remote and i saw yes the debug for that device is propagated from main poller to remote poller .

but even then I am not able to see the logs . in fact many times it happens like device is down or the port or iterface is down and cacti polls for a number of times and then stops but here device is up and so is the interface but why no logs ??

To Reproduce

Steps to reproduce the behavior:

1. Go to '...'

2. Click on '....'

3. Scroll down to '....'

4. See error

Expected behavior

A clear and concise description of what you expected to happen.

Screenshots

If applicable, add screenshots to help explain your problem.

Desktop (please complete the following information)

• OS: [e.g. iOS]

• Browser [e.g. chrome, safari]

• Version [e.g. 22]

Smartphone (please complete the following information)

• Device: [e.g. iPhone6]

• OS: [e.g. iOS8.1]

• Browser [e.g. stock browser, safari]

• Version [e.g. 22]

Additional context

Add any other context about the problem here.

[TheWitness]

Gopal,

If your check the poller cache for this device, it's likely empty. This is an issue that was discovered and fixed in the upcoming 1.2.20 release which is delayed due to some last minute scalability enhancements to the security algorithms.

The short term work around it to repopulate the poller cache from device edit.

Mark is saying April 2nd for release as he wants people testing and reporting back. It's going to be a big release from my perspective.

Larry

[gj00354347]

Thanks Larry ,

but in fact I checked the poller_cache and it was there , and in fact out of 20 graphs 15 were being populated and rest 5 were nan I forgot to mention this in ticket .

so what I was expecting like in spine we should have those 15 graphs' items output but that is what was also missing . so any pointers for this like why it happened and what I could check next time .

regarding that logs not coming in cacti , i removed those graphs and created new ones and they are being populated .Hope 1.2.20 fixes it .

Best Regards,
Gopal

[TheWitness]

Maybe @bmfmancini might have some tips. There was a bug he identified in lib/poller.php that was blocking proper replication. Also check the orphan column in data_local. If it 1, it was removed due to a reached event.

[gj00354347]

yes Larry I checked for orphan column in remote db which is used for polling as well as central db , i do not find value 1 .
but yes thanks for giving one pointer like on central db , where I created 3 fresh graphs , I believe those are not pushed to remote db .

I checked in local_data , but this is a trouble I think as this happened twice with me .on central db i see 32 rows for that device (as i informed like for 3 non working graphs I created fresh graphs) but on remote db i see only 29 rows in local_data .

PFB output from remote db

MariaDB [cacti]> select * from data_local where host_id=323;
+--------+------------------+---------+---------------+------------+--------+
| id | data_template_id | host_id | snmp_query_id | snmp_index | orphan |
+--------+------------------+---------+---------------+------------+--------+
| 4537 | 6 | 323 | 0 | | 0 |
| 13994 | 67 | 323 | 0 | | 0 |
| 13995 | 68 | 323 | 0 | | 0 |
| 460936 | 220 | 323 | 0 | | 0 |
| 594475 | 240 | 323 | 0 | | 0 |
| 575239 | 2 | 323 | 1 | 11 | 0 |
| 575240 | 2 | 323 | 1 | 12 | 0 |
| 575241 | 2 | 323 | 1 | 13 | 0 |
| 575242 | 3 | 323 | 1 | 1 | 0 |
| 575246 | 3 | 323 | 1 | 2 | 0 |
| 575247 | 2 | 323 | 1 | 1 | 0 |
| 575248 | 2 | 323 | 1 | 2 | 0 |
| 575249 | 2 | 323 | 1 | 26 | 0 |
| 575250 | 2 | 323 | 1 | 29 | 0 |
| 575251 | 2 | 323 | 1 | 30 | 0 |
| 575252 | 2 | 323 | 1 | 31 | 0 |
| 575253 | 2 | 323 | 1 | 32 | 0 |
| 575254 | 2 | 323 | 1 | 33 | 0 |
| 575255 | 2 | 323 | 1 | 34 | 0 |
| 575256 | 2 | 323 | 1 | 35 | 0 |
| 575257 | 2 | 323 | 1 | 36 | 0 |
| 580561 | 2 | 323 | 1 | 15 | 0 |
| 580562 | 2 | 323 | 1 | 16 | 0 |
| 580563 | 2 | 323 | 1 | 25 | 0 |
| 580564 | 2 | 323 | 1 | 27 | 0 |
| 580565 | 2 | 323 | 1 | 28 | 0 |
| 575258 | 31 | 323 | 4 | 1 | 0 |
| 575259 | 31 | 323 | 4 | 5 | 0 |
| 575260 | 31 | 323 | 4 | 8 | 0 |
+--------+------------------+---------+---------------+------------+--------+
29 rows in set (0.01 sec)

now on central db

MariaDB [cacti]> select * from data_local where host_id=323;
+--------+------------------+---------+---------------+------------+--------+
| id | data_template_id | host_id | snmp_query_id | snmp_index | orphan |
+--------+------------------+---------+---------------+------------+--------+
| 4537 | 6 | 323 | 0 | | 0 |
| 13994 | 67 | 323 | 0 | | 0 |
| 13995 | 68 | 323 | 0 | | 0 |
| 460936 | 220 | 323 | 0 | | 0 |
| 594475 | 240 | 323 | 0 | | 0 |
| 575239 | 2 | 323 | 1 | 11 | 0 |
| 575240 | 2 | 323 | 1 | 12 | 0 |
| 575241 | 2 | 323 | 1 | 13 | 0 |
| 575242 | 3 | 323 | 1 | 1 | 0 |
| 575246 | 3 | 323 | 1 | 2 | 0 |
| 575247 | 2 | 323 | 1 | 1 | 0 |
| 575248 | 2 | 323 | 1 | 2 | 0 |
| 575249 | 2 | 323 | 1 | 26 | 0 |
| 575250 | 2 | 323 | 1 | 29 | 0 |
| 575251 | 2 | 323 | 1 | 30 | 0 |
| 575252 | 2 | 323 | 1 | 31 | 0 |
| 575253 | 2 | 323 | 1 | 32 | 0 |
| 575254 | 2 | 323 | 1 | 33 | 0 |
| 575255 | 2 | 323 | 1 | 34 | 0 |
| 575256 | 2 | 323 | 1 | 35 | 0 |
| 575257 | 2 | 323 | 1 | 36 | 0 |
| 580561 | 2 | 323 | 1 | 15 | 0 |
| 580562 | 2 | 323 | 1 | 16 | 0 |
| 580563 | 2 | 323 | 1 | 25 | 0 |
| 580564 | 2 | 323 | 1 | 27 | 0 |
| 580565 | 2 | 323 | 1 | 28 | 0 |
| 647383 | 3 | 323 | 1 | 11 | 0 |
| 647384 | 3 | 323 | 1 | 12 | 0 |
| 647385 | 3 | 323 | 1 | 13 | 0 |
| 575258 | 31 | 323 | 4 | 1 | 0 |
| 575259 | 31 | 323 | 4 | 5 | 0 |
| 575260 | 31 | 323 | 4 | 8 | 0 |
+--------+------------------+---------+---------------+------------+--------+
32 rows in set (0.02 sec)

anyway let me do a sync and then I update you .

[TheWitness]

I'm guessing that that settings is not replicated to the remote. I'm going to check, but on the local, it's working well (for one device at least). Checking a few more things.

[TheWitness]

Okay, digging in deeper, found that when you set a device into debug mode, that setting choice is not replicated to the remote data collectors. I'm going to be making an update here shortly, but I have to check some additional areas where this needs to happen.