[dev.icinga.com #2964] pnp4nagios gives RRD errors since icinga 1.7.1

[icinga-migration]

This issue has been migrated from Redmine: https://dev.icinga.com/issues/2964

Created by calestyo on 2012-08-06 21:30:27 +00:00

Assignee: mfriedrich
Status: Resolved (closed on 2012-08-27 12:49:26 +00:00)
Target Version: 1.7.2
Last Update: 2012-08-27 12:49:26 +00:00 (in Redmine)

Icinga Version: 1.7.1-2
OS Version: Debian 6

---

Hi.

That's originally from: http://sourceforge.net/mailarchive/message.php?msg\_id=29637091

Since (as Jörg Linge, PNP upstream author, mentioned) Icinga 1.7.1,... PNP4Nagios (I guess I better call it just PNP ;-) ) gives loads of errors like these:
2012-08-06 00:11:25 [9204] [0] RRDs::update
/var/lib/pnp4nagios/perfdata/host-24.example.org/load.rrd
1344204681:0.000:0.060:0.060
2012-08-06 00:11:25 [9204] [0] RRDs::update ERROR
/var/lib/pnp4nagios/perfdata/host-24.example.org/load.rrd: illegal
attempt to update using time 1344204681 when last update time is
1344204681 (minimum one second step)
2012-08-06 00:11:25 [9204] [0] RRDs::update
/var/lib/pnp4nagios/perfdata/host-35.grid.lrz-muenchen.de/load.rrd
1344204681:0.010:0.050:0.050
2012-08-06 00:11:25 [9204] [0] RRDs::update ERROR
/var/lib/pnp4nagios/perfdata/host-35.grid.lrz-muenchen.de/load.rrd:
illegal attempt to update using time 1344204681 when last update time is
1344204681 (minimum one second step)
2012-08-06 00:12:25 [9756] [0] RRDs::update
/var/lib/pnp4nagios/perfdata/host-24.example.org/load.rrd
1344204741:0.000:0.050:0.060
2012-08-06 00:12:25 [9756] [0] RRDs::update ERROR
/var/lib/pnp4nagios/perfdata/host-24.example.org/load.rrd: illegal
attempt to update using time 1344204741 when last update time is
1344204741 (minimum one second step)
2012-08-06 00:12:25 [9756] [0] RRDs::update
/var/lib/pnp4nagios/perfdata/host-35.grid.lrz-muenchen.de/load.rrd
1344204741:0.000:0.040:0.050
2012-08-06 00:12:25 [9756] [0] RRDs::update ERROR
/var/lib/pnp4nagios/perfdata/host-35.grid.lrz-muenchen.de/load.rrd:
illegal attempt to update using time 1344204741 when last update time is
1344204741 (minimum one second step)

In the logfile for process_perfdata.pl.

According to Jörg, the problem might be in Icinga, and he suggested that I could already open a but (he'll come up with add on information later).

So here it is :)
Chris.

---

Relations:

• relates #2964
• relates #2964

[icinga-migration]

Updated by mfriedrich on 2012-08-07 15:10:20 +00:00

• Status changed from New to Feedback
• Icinga Version set to 1
• OS Version set to RHEL 5.8

that has been discussed here as well.
http://www.monitoring-portal.org/wbb/index.php?page=Thread&threadID=26352

yet, i have no idea. my systems run fine (using npcd with bulk mode, rrdcached).

[icinga-migration]

Updated by calestyo on 2012-08-07 15:13:17 +00:00

btw: I'm using npcdmod.

[icinga-migration]

Updated by mfriedrich on 2012-08-07 15:19:49 +00:00

which os, and i might guess - which package source?

[icinga-migration]

Updated by calestyo on 2012-08-07 15:24:00 +00:00

sorry:
Debian

icinga: 1.7.1-2
rrdtool: 1.4.3-1

[icinga-migration]

Updated by mfriedrich on 2012-08-07 15:32:34 +00:00

• Icinga Version changed from 1 to 1
• OS Version changed from RHEL 5.8 to Debian 6

i was asking, as we are testing custom mandatory fields in redmine - namely icinga and os version. as well as for referencing.

[icinga-migration]

Updated by calestyo on 2012-08-07 15:40:59 +00:00

Ok....

As usual,.. if you need more data or testing from my side.... do not hesitate to ask... and I'll try what I can do :)

[icinga-migration]

Updated by ossmon on 2012-08-08 11:54:58 +00:00

hi, i can confirm this problem in our environment

[icinga-migration]

Updated by mfriedrich on 2012-08-19 18:36:11 +00:00

• Category set to Events
• Status changed from Feedback to Assigned
• Assigned to set to mfriedrich
• Target Version set to 1.7.2

could you please test, using one of the following options?

• current r1.7 git branch
• https://git.icinga.org/?p=icinga-core.git;a=commit;h=379b71295b4846195590350ccb309b3ec79212da and https://git.icinga.org/?p=icinga-core.git;a=commit;h=f32fbf844589c4e1ea15f3da5175b4828de47773
• http://build.icinga.org/snapshots/icinga-core-r1.7-CURRENT.tar.gz

[icinga-migration]

Updated by tgelf on 2012-08-22 13:07:55 +00:00

Hi,

just a wild guess that might help to resolve this issue - or at least be related to it:

• PNP wants a timestamp in the TIMET field of your perfdata spool files
• You can configure it's content in host_*_file_template
• Docs on pnp4nagios.org suggests TIMET::$TIMET$
• This is problematic if you are either flooding Icinga with a peak of passive check result or with check periods being smaller than your perfdata file rotation interval
• Doing so you'll see the collisions you've met
• $LAST*CHECK$ could help here
• However this is not possible when using npcdmod: it uses *chkdata->timestamp
• It seems that broker_*_check in Icinga is mostly called with timestamp = NULL
• This will result in timestamp = time() - and you'll see the same collisions
• Using end_time (or start/execution_time) at this place might help, as the timestamp field always tells you when the event is brokered - and this is NOT the check execution time
• So I'd opt for fixing this in PNP4Nagios

Well, that's all - I hope this helps :-)

Cheers,
Thomas Gelf

[icinga-migration]

Updated by calestyo on 2012-08-22 13:51:46 +00:00

Michael, I haven't hat time yet for testing your patches,... Jörg have you had?

Thomas, I doubt that this is a TIMET related problem... because all my checks are made actively and the ones with perfdata at a per minute frequency.
So that shouldn't be able to cause conflicts, right?

[icinga-migration]

Updated by tgelf on 2012-08-22 14:04:06 +00:00

@calestyo: well, my reply didn't want do state that there is no related Icinga bug - there might also be such :) However this could still affect you if your system is under high load, suffers temporarily from high latencies or a reaper frequency higher then your process-perfdata-file interval.

I've met it excessively with passive results once they got forcibly delayed and then submitted in bulk packages.

Cheers,
Thomas

[icinga-migration]

Updated by mfriedrich on 2012-08-27 12:49:26 +00:00

• Status changed from Assigned to Resolved
• Done % changed from 0 to 100

i consider the originating issue resolved. regarding the issue with the checkresult reaper - please open a new issue, summarizing your concerns. and explain your setup in detail - as talked on irc.