Oddness with script output

[xminos]

I'm having a weird issue with a custom script I wrote that pulls data for cacti. The data input looks good and so does the data/graph templates.

This script just pulls a two digit number between 0 and 100 (it's a percent). But cacti seems to plot a random number or just ends up plotting zero.

I think im missing something obvious but I'll be damned if I can find it. I would greatly appreciate any input or suggestions.

Here is what the rrd file says it has..

bash-3.2$ rrdtool fetch /var/www/html/cacti-0.8.7e/rra/dhcp-1_dhcppercent_9779.rrd LAST
dhcppercent
<Snip>
1274726700: nan
1274727000: 0.0000000000e+00
1274727300: 0.0000000000e+00
1274727600: 5.0883333333e+00
1274727900: 5.0883333333e+00
1274728200: 0.0000000000e+00
1274728500: 0.0000000000e+00
1274728800: 0.0000000000e+00
1274729100: 4.9700000000e+00
1274729400: 0.0000000000e+00
1274729700: nan
1274730000: nan

Everytime I pull it by hand though it shows the proper output.

bash-3.2$ spine -C=/usr/etc/spine.conf -V=4 71 71
SPINE: Using spine config file [/usr/etc/spine.conf]
SPINE: Version 0.8.7e starting
ERROR: Spine Log File Could Not Be Opened/Created
05/24/2010 12:20:32 PM - SPINE: Poller[0] Host[71] SNMP Result: Host responded to SNMP
05/24/2010 12:20:32 PM - SPINE: Poller[0] Host[71] NOTE: There are '9' Polling Items for this Host
05/24/2010 12:20:46 PM - SPINE: Poller[0] Host[71] DS[9779] SCRIPT: /usr/bin/python /var/www/html/cacti-0.8.7e/scripts/cacti_dhcp_stats.py <removed>, output: 71
05/24/2010 12:20:46 PM - SPINE: Poller[0] Host[71] DS[889] SNMP: v2: <removed>, dsname: dhcpdSnmpPoolExpire, oid: .1.3.6.1.4.1.21695.1.2.2.5.1, value: 19973
05/24/2010 12:20:46 PM - SPINE: Poller[0] Host[71] DS[889] SNMP: v2: <removed>, dsname: dhcpdSnmpPoolAvaila, oid: .1.3.6.1.4.1.21695.1.2.2.6.1, value: 26401
05/24/2010 12:20:46 PM - SPINE: Poller[0] Host[71] DS[889] SNMP: v2: <removed>, dsname: dhcpdSnmpPoolActive, oid: .1.3.6.1.4.1.21695.1.2.2.4.1, value: 59600
05/24/2010 12:20:46 PM - SPINE: Poller[0] Host[71] DS[890] SNMP: v2: <removed>, dsname: dhcpdSnmpPoolSize, oid: .1.3.6.1.4.1.21695.1.2.2.3.2, value: 49143
05/24/2010 12:20:46 PM - SPINE: Poller[0] Host[71] DS[890] SNMP: v2: <removed>, dsname: dhcpdSnmpPoolActive, oid: .1.3.6.1.4.1.21695.1.2.2.4.2, value: 36765
05/24/2010 12:20:46 PM - SPINE: Poller[0] Host[71] DS[890] SNMP: v2: <removed>, dsname: dhcpdSnmpPoolAvaila, oid: .1.3.6.1.4.1.21695.1.2.2.6.2, value: 12378
05/24/2010 12:20:46 PM - SPINE: Poller[0] Host[71] DS[890] SNMP: v2: <removed>, dsname: dhcpdSnmpPoolExpire, oid: .1.3.6.1.4.1.21695.1.2.2.5.2, value: 12361
05/24/2010 12:20:46 PM - SPINE: Poller[0] Host[71] DS[889] SNMP: v2: <removed>, dsname: dhcpdSnmpPoolSize, oid: .1.3.6.1.4.1.21695.1.2.2.3.1, value: 86001
05/24/2010 12:20:46 PM - SPINE: Poller[0] Time: 14.0911 s, Threads: 100, Hosts: 2

It even appears to be plotting it within MYSQL

05/24/2010 11:28:51 AM - SPINE: Poller[0] DEVDBG: SQL:'INSERT INTO poller_output (local_data_id, rrd_name, time, output) VALUES (889,'dhcpdSnmpPoolExpire','2010-05-24 11:28:33','19957'),(889,'dhcpdSnmpPoolAvaila','2010-05-24 11:28:33','26398'),(889,'dhcpdSnmpPoolActive','2010-05-24 11:28:33','59603'),(890,'dhcpdSnmpPoolSize','2010-05-24 11:28:33','49143'),(890,'dhcpdSnmpPoolActive','2010-05-24 11:28:33','36730'),(890,'dhcpdSnmpPoolAvaila','2010-05-24 11:28:33','12413'),(890,'dhcpdSnmpPoolExpire','2010-05-24 11:28:33','12396'),(8356,'dhcppercent','2010-05-24 11:28:33','71
'),(889,'dhcpdSnmpPoolSize','2010-05-24 11:28:33','86001')'05/24/2010 11:28:51 AM - SPINE: Poller[0] Host[71] DEBUG: HOST COMPLETE: About to Exit Host Polling Thread Function

But here is what the graph shows..



So I see the rrd file doesn't have the proper data, and the graph is pulling from that. What is causing the wrong data to be stored in the rrd file?

Here is my data input:


My data template




The graph template

[BSOD2600]

1) Need to track down the 'rrdtool update' command in the DEBUG cacti.log for that data source/script each polling cycle to see what's going on.

2) 'rrdtool info' on the rrd file being used.

3) graph debug output.

[xminos]

Thanks for the reply BSOD. I'll try to flip on debug long enough to grab the rrdtool update.

In the mean while. Here is the rrdtool info and the debug output.

RRDTool Command:
/usr/bin/rrdtool graph - \
--imgformat=PNG \
--start=-86400 \
--end=-300 \
--title="DHCP-1 - Pool Usage" \
--rigid \
--base=1000 \
--height=120 \
--width=500 \
--alt-autoscale-max \
--lower-limit=0 \
--vertical-label="percent" \
--slope-mode \
--font TITLE:8: \
--font AXIS:8: \
--font LEGEND:10: \
--font UNIT:8: \
DEF:a="/var/www/html/cacti-0.8.7e/rra/dhcp-1_dhcppercent_9779.rrd":dhcppercent:LAST \
LINE3:a#FF00FFFF:"Pool Usage" \
GPRINTLAST:"Current\:%8.0lf" \
GPRINTAVERAGE:"Average\:%8.0lf" \
GPRINTMAX:"Maximum\:%8.0lf"

:/var/www/html/cacti/rra> rrdtool info dhcp-1_dhcppercent_9779.rrd
filename = "dhcp-1_dhcppercent_9779.rrd"
rrd_version = "0003"
step = 300
last_update = 1274756102
ds[dhcppercent].type = "GAUGE"
ds[dhcppercent].minimal_heartbeat = 600
ds[dhcppercent].min = 0.0000000000e+00
ds[dhcppercent].max = NaN
ds[dhcppercent].last_ds = "0"
ds[dhcppercent].value = 0.0000000000e+00
ds[dhcppercent].unknown_sec = 0
rra[0].cf = "AVERAGE"
rra[0].rows = 600
rra[0].pdp_per_row = 1
rra[0].xff = 5.0000000000e-01
rra[0].cdp_prep[0].value = NaN
rra[0].cdp_prep[0].unknown_datapoints = 0
rra[1].cf = "AVERAGE"
rra[1].rows = 700
rra[1].pdp_per_row = 6
rra[1].xff = 5.0000000000e-01
rra[1].cdp_prep[0].value = 0.0000000000e+00
rra[1].cdp_prep[0].unknown_datapoints = 0
rra[2].cf = "AVERAGE"
rra[2].rows = 775
rra[2].pdp_per_row = 24
rra[2].xff = 5.0000000000e-01
rra[2].cdp_prep[0].value = 0.0000000000e+00
rra[2].cdp_prep[0].unknown_datapoints = 0
rra[3].cf = "AVERAGE"
rra[3].rows = 797
rra[3].pdp_per_row = 288
rra[3].xff = 5.0000000000e-01
rra[3].cdp_prep[0].value = 0.0000000000e+00
rra[3].cdp_prep[0].unknown_datapoints = 0
rra[4].cf = "MIN"
rra[4].rows = 600
rra[4].pdp_per_row = 1
rra[4].xff = 5.0000000000e-01
rra[4].cdp_prep[0].value = NaN
rra[4].cdp_prep[0].unknown_datapoints = 0
rra[5].cf = "MIN"
rra[5].rows = 700
rra[5].pdp_per_row = 6
rra[5].xff = 5.0000000000e-01
rra[5].cdp_prep[0].value = 0.0000000000e+00
rra[5].cdp_prep[0].unknown_datapoints = 0
rra[6].cf = "MIN"
rra[6].rows = 775
rra[6].pdp_per_row = 24
rra[6].xff = 5.0000000000e-01
rra[6].cdp_prep[0].value = 0.0000000000e+00
rra[6].cdp_prep[0].unknown_datapoints = 0
rra[7].cf = "MIN"
rra[7].rows = 797
rra[7].pdp_per_row = 288
rra[7].xff = 5.0000000000e-01
rra[7].cdp_prep[0].value = 0.0000000000e+00
rra[7].cdp_prep[0].unknown_datapoints = 0
rra[8].cf = "MAX"
rra[8].rows = 600
rra[8].pdp_per_row = 1
rra[8].xff = 5.0000000000e-01
rra[8].cdp_prep[0].value = NaN
rra[8].cdp_prep[0].unknown_datapoints = 0
rra[9].cf = "MAX"
rra[9].rows = 700
rra[9].pdp_per_row = 6
rra[9].xff = 5.0000000000e-01
rra[9].cdp_prep[0].value = 0.0000000000e+00
rra[9].cdp_prep[0].unknown_datapoints = 0
rra[10].cf = "MAX"
rra[10].rows = 775
rra[10].pdp_per_row = 24
rra[10].xff = 5.0000000000e-01
rra[10].cdp_prep[0].value = 0.0000000000e+00
rra[10].cdp_prep[0].unknown_datapoints = 0
rra[11].cf = "MAX"
rra[11].rows = 797
rra[11].pdp_per_row = 288
rra[11].xff = 5.0000000000e-01
rra[11].cdp_prep[0].value = 0.0000000000e+00
rra[11].cdp_prep[0].unknown_datapoints = 0
rra[12].cf = "LAST"
rra[12].rows = 600
rra[12].pdp_per_row = 1
rra[12].xff = 5.0000000000e-01
rra[12].cdp_prep[0].value = NaN
rra[12].cdp_prep[0].unknown_datapoints = 0
rra[13].cf = "LAST"
rra[13].rows = 700
rra[13].pdp_per_row = 6
rra[13].xff = 5.0000000000e-01
rra[13].cdp_prep[0].value = 0.0000000000e+00
rra[13].cdp_prep[0].unknown_datapoints = 0
rra[14].cf = "LAST"
rra[14].rows = 775
rra[14].pdp_per_row = 24
rra[14].xff = 5.0000000000e-01
rra[14].cdp_prep[0].value = 0.0000000000e+00
rra[14].cdp_prep[0].unknown_datapoints = 0
rra[15].cf = "LAST"
rra[15].rows = 797
rra[15].pdp_per_row = 288
rra[15].xff = 5.0000000000e-01
rra[15].cdp_prep[0].value = 0.0000000000e+00
rra[15].cdp_prep[0].unknown_datapoints = 0