rrdtool mis-logging values close to NaNs

[human]

My logger did this:

Nov 21 16:26:27 smurf HomEvenT: EVENT: monitor¦value¦5.875¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:27:04 smurf HomEvenT: EVENT: monitor¦value¦5.84375¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:27:42 smurf HomEvenT: EVENT: monitor¦value¦5.84375¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:28:20 smurf HomEvenT: EVENT: monitor¦value¦5.78125¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:28:58 smurf HomEvenT: EVENT: monitor¦value¦5.6875¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:29:59 smurf HomEvenT: EVENT: monitor¦value¦5.75¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:30:37 smurf HomEvenT: EVENT: monitor¦value¦5.6875¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:31:15 smurf HomEvenT: EVENT: monitor¦value¦5.75¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:31:52 smurf HomEvenT: EVENT: monitor¦value¦5.75¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:32:30 smurf HomEvenT: EVENT: monitor¦value¦5.75¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:33:08 smurf HomEvenT: EVENT: monitor¦value¦5.6875¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:33:46 smurf HomEvenT: EVENT: monitor¦value¦5.71875¦temperatur¦aussen¦vorne¦sensor
Nov 21 16:34:24 smurf HomEvenT: EVENT: monitor¦value¦5.8125¦temperatur¦aussen¦vorne¦sensor

on this RRD:

<!-- Round Robin Database Dump --><rrd> <version> 0003 </version>
        <step> 60 </step> <!-- Seconds -->
        <lastupdate> 1195660905 </lastupdate> <!-- 2007-11-21 17:01:45 CET -->

        <ds>
                <name> temp </name>
                <type> GAUGE </type>
                <minimal_heartbeat> 60 </minimal_heartbeat>
                <min> -3.0000000000e+01 </min>
                <max> 1.0000000000e+02 </max>

                <!-- PDP Status -->
                <last_ds> UNKN </last_ds>
                <value> 2.6494687553e+02 </value>
                <unknown_sec> 0 </unknown_sec>
        </ds>

<!-- Round Robin Archives -->   <rra>
                <cf> MIN </cf>
                <pdp_per_row> 1 </pdp_per_row> <!-- 60 seconds -->

                <params>
                <xff> 9.0000000000e-01 </xff>
                </params>
                <cdp_prep>
                        <ds>
                        <primary_value> 5.7806384167e+00 </primary_value>
                        <secondary_value> NaN </secondary_value>
                        <value> NaN </value>
                        <unknown_datapoints> 0 </unknown_datapoints>
                        </ds>
                </cdp_prep>
                <database>
[...]

which caused these values to be logged:

                        <!-- 2007-11-21 16:24:00 CET / 1195658640 --> <row><v> 5.8644450146e+00 </v></row>
                        <!-- 2007-11-21 16:25:00 CET / 1195658700 --> <row><v> 5.9862567760e+00 </v></row>
                        <!-- 2007-11-21 16:26:00 CET / 1195658760 --> <row><v> 5.9324805292e+00 </v></row>
                        <!-- 2007-11-21 16:27:00 CET / 1195658820 --> <row><v> 5.8579789802e+00 </v></row>
                        <!-- 2007-11-21 16:28:00 CET / 1195658880 --> <row><v> 5.8257040052e+00 </v></row>
                        <!-- 2007-11-21 16:29:00 CET / 1195658940 --> <row><v> NaN </v></row>
                        <!-- 2007-11-21 16:30:00 CET / 1195659000 --> <row><v> 6.8172081250e-01 </v></row>
                        <!-- 2007-11-21 16:31:00 CET / 1195659060 --> <row><v> 5.7109205031e+00 </v></row>
                        <!-- 2007-11-21 16:32:00 CET / 1195659120 --> <row><v> 5.7500000000e+00 </v></row>
                        <!-- 2007-11-21 16:33:00 CET / 1195659180 --> <row><v> 5.7192732573e+00 </v></row>
                        <!-- 2007-11-21 16:34:00 CET / 1195659240 --> <row><v> 5.7356776490e+00 </v></row>
                        <!-- 2007-11-21 16:35:00 CET / 1195659300 --> <row><v> 5.8311675089e+00 </v></row>

Note the stupid almost-zero number at 16:30:00. I did NOT log that, or anything else that's not in the above protocol.

Version: 1.2.15-0.3ubuntu1

[oetiker]

You told rrdtool NOT to accept any values further than 60 seconds apart (minimal required heart beat 60) which it does ... please use the mailinglist for support questions.

[human]

??? Sorry, but ... did you actually read the bug report?

I'm not complaining about rrdtool not accepting values further apart than 60 seconds. That is not the problem. I know why that NaN is in there. That's fine.

The problem is the stray value that shows up in the RRD (and the resulting graph of course) directly after the NaN. It's just plain wrong.

In short: The graph shows a weird downwards spike which does not correspond to any actual measurement.

[oetiker]

This was caused by the bug fixed in r1340. Thanks for reporting.

[human]

 #125 (rrdtool mis-logging values close to NaNs) – RRDtool Trac