[RESOLVED] Quotes not stripped on recache

[Setarcos]

Hi Folks,

I have been working with TheWitness to hammer out Spine bugs in SVN and recently ran across a potentially long-standing issue with my setup or spine. At this point, I am not sure where to look.

With the poller logging cranked up to Debug, I see warnings like the following:

Code: Select all

05/04/2010 01:35:02 PM - SPINE: Poller[0] Host[13] ASSERT: '0000027F2193-0' .eq. '"0000027F2193-0"' failed. Recaching host '10.40.10.1', data query #10

Normally, when indexed SNMP queries indexes don't match I see something like:

Code: Select all

05/04/2010 01:40:04 PM - SPINE: Poller[0] Host[502] ASSERT: '72' .eq. '73' failed. Recaching host '10.250.17.254', data query #28

which is expected behavior when things need to be reindexed.

The question I have is why does the first example attempting to compare strings with an extra set of quotes? The SNMP value is indeed a string, but It looks like the quotes need to be stripped somewhere before comparing.

[gandalf]

Which Cacti version are you using, then?
R.

[Setarcos]

Which Cacti version are you using, then?
R.

Hi gandalf, here is the Tech Support dump from my larger instance where this issue first surfaced:

Code: Select all

Technical Support

General Information

Date 	Wed, 05 May 2010 06:18:26 -0700
Cacti Version 	0.8.7e
Cacti OS 	unix
SNMP Version 	NET-SNMP version: 5.3.2.2
RRDTool Version 	RRDTool 1.2.x
Hosts 	421
Graphs 	12985
Data Sources 	Script/Command: 586
SNMP: 2297
SNMP Query: 10037
Script Query: 454
Script - Script Server (PHP): 1
Script Query - Script Server: 1527
Total: 14902


Poller Information

Interval 	300
Type 	spine
Items 	Action[0]: 14730
Action[1]: 1168
Action[2]: 2149
Total: 18047
Concurrent Processes 	8
Max Threads 	40
PHP Servers 	5
Script Timeout 	120
Max OID 	35
Last Run Statistics 	Time:38.5425 Method:spine Processes:8 Threads:40 Hosts:414 HostsPerProcess:52 DataSources:18047 RRDsProcessed:14131


PHP Information

PHP Version 	5.1.6
PHP OS 	Linux
PHP uname 	Linux DL360-3 2.6.18-194.el5xen #1 SMP Tue Mar 16 22:01:26 EDT 2010 x86_64
PHP SNMP 	Installed
max_execution_time 	120
memory_limit 	512M

Spine 0.8.7a (and subsequent versions) show this warning, but recent SVN versions started generating gaps for these data sources leading to the discovery of the issue.

[Setarcos]

I had a peek at the poller_reindex table in the cacti DB, and see entries corresponding with the additional quotes, but they seem to vary from run-to-run with spine:

Spine polling:

Code: Select all

mysql> select * from poller_reindex where assert_value like "%\"%";
+---------+---------------+--------+----+------------------+-----------------------------+
| host_id | data_query_id | action | op | assert_value     | arg1                        |
+---------+---------------+--------+----+------------------+-----------------------------+
|     132 |            10 |      0 | =  | "000002802B3B-0" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|      21 |            10 |      0 | =  | "0000027F1802-1" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|     337 |            10 |      0 | =  | "000002802BCF-0" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|      70 |            10 |      0 | =  | "DC0S3P1"        | .1.3.6.1.4.1.xxxx.1.1.1.2.4 |
|      70 |            10 |      0 | =  | "DC0S2P1"        | .1.3.6.1.4.1.xxxx.1.1.1.2.3 |
|      70 |            10 |      0 | =  | "DC0S3P0"        | .1.3.6.1.4.1.xxxx.1.1.1.2.2 |
|      70 |            10 |      0 | =  | "DC0S2P0"        | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|     337 |            10 |      0 | =  | "000002802B9E-0" | .1.3.6.1.4.1.xxxx.1.1.1.2.4 |
|     337 |            10 |      0 | =  | "000002802BCF-1" | .1.3.6.1.4.1.xxxx.1.1.1.2.3 |
|      48 |            10 |      0 | =  | "DC3S0P0"        | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|      41 |            10 |      0 | =  | "00000167B229-1" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|      83 |            10 |      0 | =  | "000002802B70-1" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|     337 |            10 |      0 | =  | "24444238933-0"  | .1.3.6.1.4.1.xxxx.1.1.1.2.2 |
|     341 |            10 |      0 | =  | "000002802B89-1" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|      37 |            10 |      0 | =  | "DC0S5P0"        | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|      13 |            10 |      0 | =  | "0000027F2193-0" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|     276 |            10 |      0 | =  | "000002802B68-0" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|     353 |            10 |      0 | =  | "000002802B80-1" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|      87 |            10 |      0 | =  | "0000016815FC-1" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
+---------+---------------+--------+----+------------------+-----------------------------+

Between polling cycles:

Code: Select all

mysql> select * from poller_reindex where assert_value like "%\"%";
+---------+---------------+--------+----+------------------+-----------------------------+
| host_id | data_query_id | action | op | assert_value     | arg1                        |
+---------+---------------+--------+----+------------------+-----------------------------+
|     337 |            10 |      0 | =  | "000002802BCF-0" | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|      70 |            10 |      0 | =  | "DC0S3P1"        | .1.3.6.1.4.1.xxxx.1.1.1.2.4 |
|      70 |            10 |      0 | =  | "DC0S2P1"        | .1.3.6.1.4.1.xxxx.1.1.1.2.3 |
|      70 |            10 |      0 | =  | "DC0S3P0"        | .1.3.6.1.4.1.xxxx.1.1.1.2.2 |
|      70 |            10 |      0 | =  | "DC0S2P0"        | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
|     337 |            10 |      0 | =  | "000002802B9E-0" | .1.3.6.1.4.1.xxxx.1.1.1.2.4 |
|     337 |            10 |      0 | =  | "000002802BCF-1" | .1.3.6.1.4.1.xxxx.1.1.1.2.3 |
|     337 |            10 |      0 | =  | "24444238933-0"  | .1.3.6.1.4.1.xxxx.1.1.1.2.2 |
+---------+---------------+--------+----+------------------+-----------------------------+

mysql> select * from poller_reindex where host_id = 13 and data_query_id = 10 and arg1 = ".1.3.6.1.4.1.xxxx.1.1.1.2.1";
+---------+---------------+--------+----+----------------+-----------------------------+
| host_id | data_query_id | action | op | assert_value   | arg1                        |
+---------+---------------+--------+----+----------------+-----------------------------+
|      13 |            10 |      0 | =  | 0000027F2193-0 | .1.3.6.1.4.1.xxxx.1.1.1.2.1 |
+---------+---------------+--------+----+----------------+-----------------------------+

If I had to hazard a guess, trim() isn't getting called some of the time before values get stuffed into the table...

[TheWitness]

So, are you around. I'd like to get to the bottom of this right now....

[Setarcos]

So, are you around. I'd like to get to the bottom of this right now....

Yep, I am available for the rest of the afternoon.

[Setarcos]

Thanks again TheWitness for your time this afternoon looking into this with me.

I have been running the small instance on the new code since I left the office and things look good. I just ran a short test on the larger instance, and the extra "" issue when determining if reindexing is needed appears to be resolved. However, the graph gap issue remains with the updated spine so I have some more investigative work to do.

[Setarcos]

Marked this issue as resolved, but will open up a new thread in Unstable Development Versions for the graph gap issue as this appears to be related to the SVN version of spine.

[sguido]

So what was the fix for this? Is it a problem with the source code or only a problem at your site? Thanks.

[Setarcos]

So what was the fix for this? Is it a problem with the source code or only a problem at your site? Thanks.

The problem where quotes were not being stripped in recache was a spine bug that is resolved by Spine SVN 5871.