Nagios Support Forum

Hi All,
I have been trying to get a Nagios Core V4.3.4 instance going. My issue is that the graphs for performance data have huge gaps in them. It seems the data is being returned from the service checks, and I suspect the pnp4nagios module is not writing the data correctly into the .rrd database files. I have tried removing the .rrd files, and letting the load process create them, but the issue remains.
I did find an issue where the time was out, but I believe this has been corrected and chronyd is now correctly syncing the time.
I'm attaching some output below.
Please let me know if there is any further in required.
Many thanks for any assistance you can provide.
Rgds,
Dave.

Running on Red Hat Enterprise Linux Server release 7.3 (Maipo)
Copy of 3.x was taken and upgraded to Nagios Core 4.3.4.
Graphing worked on the 3.x version, gaps started on the 4.3.4 system

Method is bulk mode + npcd

Various errors in perfdata.log as follows:


2018-03-16 13:47:32 [44683] [0] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_errors.rrd DATATYPE::SERVICEPERFDATA:0
2018-03-16 13:47:32 [44683] [0] RRDs::update ERROR /var/lib/pnp4nagios/.pnp-internal/runtime_errors.rrd: found extra data on update argument: SERVICEPERFDATA:0
2018-03-16 13:47:32 [44684] [0] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_update.rrd 0:0
2018-03-16 13:47:32 [44684] [0] RRDs::update ERROR /var/lib/pnp4nagios/.pnp-internal/runtime_update.rrd: illegal attempt to update using time 0 when last update time is 1521225991 (minimum one second step)

2018-03-16 13:48:02 [44842] [0] RRDs::update ERROR /var/lib/pnp4nagios/.pnp-internal/runtime_rows.rrd: found extra data on update argument: HOSTPERFDATA:0

Verify_pnp_config works with what seems like mon-consequential errors:

soot@usmke1hstnagvp01l:[a212356335]: ./verify_pnp_config.pl --mode=bulk+npcd --config=/etc/nagios/nagios.cfg --pnpcfg=/etc/pnp4nagio
[INFO] ========== Starting Environment Checks ============
[INFO] My version is: verify_pnp_config-0.6.26-R.40
[INFO] Start Options: ./verify_pnp_config.pl --mode=bulk+npcd --config=/etc/nagios/nagios.cfg --pnpcfg=/etc/pnp4nagios
[INFO] Reading /etc/nagios/nagios.cfg
[OK ] Running product is 'nagios'
[OK ] object_cache_file is defined
[OK ] object_cache_file=/var/spool/nagios/objects.cache
[INFO] Reading /var/spool/nagios/objects.cache
[OK ] resource_file is defined
[OK ] resource_file=/etc/nagios/private/resource.cfg
[INFO] Reading /etc/nagios/private/resource.cfg
[INFO] Reading /etc/pnp4nagios/process_perfdata.cfg
[INFO] Reading /etc/pnp4nagios/pnp4nagios_release
[OK ] Found PNP4Nagios version "0.6.25"
[OK ] ./configure Options '--build=x86_64-redhat-linux-gnu' '--host=x86_64-redhat-linux-gnu' '--program-prefix=' '--disable-dependency-tracking' '--prefix=/usr' '--exec-prefix=/usr' '--bindir=/usr/bin' '--sbindir=/usr/sbin' '--sysconfdir=/etc' '--datadir=/usr/share' '--includedir=/usr/include' '--libdir=/usr/lib64' '--libexecdir=/usr/libexec' '--localstatedir=/var' '--sharedstatedir=/var/lib' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--bindir=/usr/sbin' '--libexecdir=/usr/libexec/pnp4nagios' '--sysconfdir=/etc/pnp4nagios' '--localstatedir=/var/log/pnp4nagios' '--datadir=/usr/share/nagios/html/pnp4nagios' '--datarootdir=/usr/share/nagios/html/pnp4nagios' '--with-perfdata-dir=/var/lib/pnp4nagios' '--with-perfdata-spool-dir=/var/spool/pnp4nagios' 'build_alias=x86_64-redhat-linux-gnu' 'host_alias=x86_64-redhat-linux-gnu' 'CFLAGS=-O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector-strong --param=ssp-buffer-size=4 -grecord-gcc-switches -m64 -mtune=generic' 'LDFLAGS=-Wl,-z,relro '
[OK ] Effective User is 'nagios'
[OK ] User nagios exists with ID '993'
[OK ] Effective group is 'nagios'
[OK ] Group nagios exists with ID '990'
[INFO] ========== Checking Bulk Mode + NPCD Config ============
[OK ] process_performance_data is 1 compared with '/1/'
[OK ] service_perfdata_file is defined
[OK ] service_perfdata_file=/var/log/pnp4nagios/stats/service-perfdata
[OK ] service_perfdata_file_template is defined
[OK ] service_perfdata_file_template=DATATYPE::SERVICEPERFDATA\tTIMET::$TIMET$\tHOSTNAME::$HOSTNAME$\tSERVICEDESC::$SERVICEDESC$\tSERVICEPERFDATA::$SERVICEPERFDATA$\tSERVICECHECKCOMMAND::$SERVICECHECKCOMMAND$\tHOSTSTATE::$HOSTSTATE$\tHOSTSTATETYPE::$HOSTSTATETYPE$\tSERVICESTATE::$SERVICESTATE$\tSERVICESTATETYPE::$SERVICESTATETYPE$
[OK ] PERFDATA template looks good
[OK ] service_perfdata_file_mode is defined
[OK ] service_perfdata_file_mode=a
[OK ] service_perfdata_file_processing_interval is defined
[OK ] service_perfdata_file_processing_interval=15
[OK ] service_perfdata_file_processing_command is defined
[OK ] service_perfdata_file_processing_command=process-service-perfdata-file
[OK ] host_perfdata_file is defined
[OK ] host_perfdata_file=/var/log/pnp4nagios/stats/host-perfdata
[OK ] host_perfdata_file_template is defined
[OK ] host_perfdata_file_template=DATATYPE::HOSTPERFDATA\tTIMET::$TIMET$\tHOSTNAME::$HOSTNAME$\tHOSTPERFDATA::$HOSTPERFDATA$\tHOSTCHECKCOMMAND::$HOSTCHECKCOMMAND$\tHOSTSTATE::$HOSTSTATE$\tHOSTSTATETYPE::$HOSTSTATETYPE$
[OK ] PERFDATA template looks good
[OK ] host_perfdata_file_mode is defined
[OK ] host_perfdata_file_mode=a
[OK ] host_perfdata_file_processing_interval is defined
[OK ] host_perfdata_file_processing_interval=15
[OK ] host_perfdata_file_processing_command is defined
[OK ] host_perfdata_file_processing_command=process-host-perfdata-file
[INFO] Nagios config looks good so far
[INFO] ========== Checking config values ============
[OK ] npcd daemon is running
[OK ] /etc/pnp4nagios/npcd.cfg is used by npcd and readable
[INFO] Reading /etc/pnp4nagios/npcd.cfg
[OK ] perfdata_spool_dir is defined
[OK ] perfdata_spool_dir=/var/spool/pnp4nagios
[OK ] -1 files found in /var/spool/pnp4nagios
service_perfdata_file_processing_command at ./verify_pnp_config.pl line 462.
[OK ] Command process-service-perfdata-file is defined
[OK ] '/bin/mv /var/log/pnp4nagios/stats/service-perfdata /var/spool/pnp4nagios/service-perfdata.$TIMET$'
[OK ] Command looks good
host_perfdata_file_processing_command at ./verify_pnp_config.pl line 462.
[OK ] Command process-host-perfdata-file is defined
[OK ] '/bin/mv /var/log/pnp4nagios/stats/host-perfdata /var/spool/pnp4nagios/host-perfdata.$TIMET$'
[OK ] Command looks good
[OK ] Script /usr/libexec/pnp4nagios/process_perfdata.pl is executable
[INFO] ========== Starting global checks ============
[OK ] status_file is defined
[OK ] status_file=/var/spool/nagios/status.dat
[INFO] host_query =
[INFO] service_query =
[INFO] Reading /var/spool/nagios/status.dat
[INFO] ==== Starting rrdtool checks ====
[OK ] RRDTOOL is defined
[OK ] RRDTOOL=/usr/bin/rrdtool
[OK ] /usr/bin/rrdtool is executable
[OK ] RRDtool 1.4.8 Copyright 1997-2013 by Tobias Oetiker <[email protected]>
[OK ] USE_RRDs is defined
[OK ] USE_RRDs=1
[OK ] Perl RRDs modules are loadable
[INFO] ==== Starting directory checks ====
[OK ] RRDPATH is defined
[OK ] RRDPATH=/var/lib/pnp4nagios
[OK ] Perfdata directory '/var/lib/pnp4nagios' exists
[WARN] 252 hosts/services are not providing performance data
[WARN] 'process_perf_data 1' is set for 166 hosts/services which are not providing performance data!
[WARN] 'process_perf_data 0' is set for 87 of your hosts/services
[OK ] 'process_perf_data 1' is set for 380 of your hosts/services
[WARN] Logging is enabled in process_perfdata.cfg. This will reduce the overall performance of PNP4Nagios
[INFO] ==== System sizing ====
[OK ] 466 hosts/service objects defined
[INFO] ==== Check statistics ====
[WARN] Warning: 4, Critical: 0
[WARN] Checks finished…

Chrondy used for time sync


Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
root@usmke1hstnagvp01l:[a212356335]: systemctl status -l chronyd
● chronyd.service - NTP client/server
Loaded: loaded (/usr/lib/systemd/system/chronyd.service; enabled; vendor preset: enabled)
Active: active (running) since Mon 2018-03-05 14:30:23 CST; 1 weeks 3 days ago
Main PID: 669 (chronyd)
Memory: 964.0K
CGroup: /system.slice/chronyd.service
└─669 /usr/sbin/chronyd


I added some additional logging for npcd:


root@usmke1hstnagvp01l:[a212356335]: systemctl status -l npcd
● npcd.service - LSB: Nagios Performancedata C Daemon
Loaded: loaded (/etc/rc.d/init.d/npcd; bad; vendor preset: disabled)
Active: active (running) since Wed 2018-03-07 09:24:51 CST; 1 weeks 2 days ago
Docs: man:systemd-sysv-generator(8)
Process: 59356 ExecStop=/etc/rc.d/init.d/npcd stop (code=exited, status=0/SUCCESS)
Process: 59446 ExecStart=/etc/rc.d/init.d/npcd start (code=exited, status=0/SUCCESS)
Memory: 41.0M
CGroup: /system.slice/npcd.service
└─59453 /usr/sbin/npcd -f /etc/pnp4nagios/npcd.cfg -d

Mar 16 13:54:03 usmke1hstnagvp01l.uhc1.local NPCD[59453]: A thread was started on thread_counter = 0
Mar 16 13:54:03 usmke1hstnagvp01l.uhc1.local NPCD[59453]: ThreadCounter 1/5 File is service-perfdata.1521226435
Mar 16 13:54:03 usmke1hstnagvp01l.uhc1.local NPCD[59453]: Regular File: service-perfdata.1521226435
Mar 16 13:54:03 usmke1hstnagvp01l.uhc1.local NPCD[59453]: A thread was started on thread_counter = 1
Mar 16 13:54:03 usmke1hstnagvp01l.uhc1.local NPCD[59453]: Have to wait: Filecounter = 2 - thread_counter = 2
Mar 16 13:54:03 usmke1hstnagvp01l.uhc1.local NPCD[59453]: Processing file host-perfdata.1521226434 with ID 140192257537792 - going to exec /usr/libexec/pnp4nagios/process_perfdata.pl -n --bulk /var/spool/pnp4nagios/host-perfdata.1521226434
Mar 16 13:54:03 usmke1hstnagvp01l.uhc1.local NPCD[59453]: Processing file 'host-perfdata.1521226434'
Mar 16 13:54:03 usmke1hstnagvp01l.uhc1.local NPCD[59453]: Processing file service-perfdata.1521226435 with ID 140192249145088 - going to exec /usr/libexec/pnp4nagios/process_perfdata.pl -n --bulk /var/spool/pnp4nagios/service-perfdata.1521226435
Mar 16 13:54:03 usmke1hstnagvp01l.uhc1.local NPCD[59453]: Processing file 'service-perfdata.1521226435'
Mar 16 13:54:03 usmke1hstnagvp01l.uhc1.local NPCD[59453]: No more files to process... waiting for 15 seconds


Just got this, which I believe is new:


root@usmke1hstnagvp01l:[a212356335]: /usr/sbin/nagios -v /etc/nagios/nagios.cfg

Nagios Core 4.3.4
Copyright (c) 2009-present Nagios Core Development Team and Community Contributors
Copyright (c) 1999-2009 Ethan Galstad
Last Modified: 2017-08-24
License: GPL

Website: https://www.nagios.org
Reading configuration data...
Read main config file okay...
WARNING: The normal_check_interval attribute is deprecated and will be removed in future versions. Please use check_interval instead.
WARNING: The retry_check_interval attribute is deprecated and will be removed in future versions. Please use retry_interval instead.
WARNING: The normal_check_interval attribute is deprecated and will be removed in future versions. Please use check_interval instead.
WARNING: The retry_check_interval attribute is deprecated and will be removed in future versions. Please use retry_interval instead.
WARNING: The normal_check_interval attribute is deprecated and will be removed in future versions. Please use check_interval instead.
WARNING: The retry_check_interval attribute is deprecated and will be removed in future versions. Please use retry_interval instead.
WARNING: The normal_check_interval attribute is deprecated and will be removed in future versions. Please use check_interval instead.
WARNING: The retry_check_interval attribute is deprecated and will be removed in future versions. Please use retry_interval instead.
WARNING: The normal_check_interval attribute is deprecated and will be removed in future versions. Please use check_interval instead.
WARNING: The retry_check_interval attribute is deprecated and will be removed in future versions. Please use retry_interval instead.
WARNING: The normal_check_interval attribute is deprecated and will be removed in future versions. Please use check_interval instead.
WARNING: The retry_check_interval attribute is deprecated and will be removed in future versions. Please use retry_interval instead.
Read object config files okay...

Running pre-flight check on configuration data...

Checking objects...
Checked 398 services.
Checked 68 hosts.
Checked 11 host groups.
Checked 0 service groups.
Checked 25 contacts.
Checked 7 contact groups.
Checked 67 commands.
Checked 10 time periods.
Checked 0 host escalations.
Checked 0 service escalations.
Checking for circular paths...
Checked 68 hosts
Checked 0 service dependencies
Checked 0 host dependencies
Checked 10 timeperiods
Checking global event handlers...
Checking obsessive compulsive processor commands...
Checking misc settings...

Total Warnings: 0
Total Errors: 0

Things look okay - No serious problems were detected during the pre-flight check

This often happens with npcd if the load on the machine is over the threshold set in the cfg

open npcd.cfg

find increase to a level over the load on your server

Thanks Scott,
I've updated the npcd.cfg file and restarted the service. I'll check it over the weekend.
Thanks,
Dave.

Hopefully that has helped some. Please feel free to share your results after it's had some time to test.

Hi,
I'm still seeing the errors in the perfdata.log and still seeing the gaps in the graphs.

2018-03-19 13:00:17 [59377] [2] data2rrd called
2018-03-19 13:00:17 [59378] [2] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_skipped.rrd 0:0
2018-03-19 13:00:17 [59378] [0] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_skipped.rrd 0:0
2018-03-19 13:00:17 [59378] [0] RRDs::update ERROR /var/lib/pnp4nagios/.pnp-internal/runtime_skipped.rrd: illegal attempt to update using time 0 when last update time is 1521482327 (minimum one second step)


2018-03-19 12:58:17 [58747] [0] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_errors.rrd DATATYPE::SERVICEPERFDATA:0
2018-03-19 12:58:17 [58747] [0] RRDs::update ERROR /var/lib/pnp4nagios/.pnp-internal/runtime_errors.rrd: found extra data on update
argument: SERVICEPERFDATA:0
2018-03-19 12:58:17 [58748] [2] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_invalid.rrd DATATYPE::HOSTPERFDATA:0
2018-03-19 12:58:17 [58748] [0] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_invalid.rrd DATATYPE::HOSTPERFDATA:0
2018-03-19 12:58:17 [58748] [0] RRDs::update ERROR /var/lib/pnp4nagios/.pnp-internal/runtime_invalid.rrd: found extra data on update
argument: HOSTPERFDATA:0

Thanks,
Dave.

Hello,
I have increased the logging level for both bath and NPCD. When I start seeing some errors I will post them.
Thanks,
Dave.

I'd like to get a copy of the nagios.cfg to review the options set as well as the template formats used. It would appear that the perfdata files(location set in nagios.cfg with service_perfdata_file and host_perfdata_file) are not getting correct information. If you "tail -f" on either/both of these files, do you see a TIMET of 0 ever? Depending on how frequently the gaps occur, you may need to let this run for a bit.

Hi,
I've attached the nagios.cfg file.
I found this article and wondered if it had any relevance, although not for Nagios Core.

https://support.nagios.com/kb/article/n ... 1496169495

I increased the logging level for npcd.
Seems like there's a couple of distinct errors.

On is:

2018-03-20 12:23:12 [59690] [1] process_perfdata.pl-0.6.25 starting in BULK Mode called by NPCD
2018-03-20 12:23:12 [59690] [2] searching for /var/spool/pnp4nagios/host-perfdata.1521566585
2018-03-20 12:23:12 [59690] [2] renaming /var/spool/pnp4nagios/host-perfdata.1521566585 to /var/spool/pnp4nagios/host-perfdata.1521566585-PID-59690 for bulk update
2018-03-20 12:23:12 [59690] [2] reading /var/spool/pnp4nagios/host-perfdata.1521566585-PID-59690 for bulk update
2018-03-20 12:23:12 [59690] [2] Processing Line 1
2018-03-20 12:23:12 [59690] [2] Datatype set to 'HOSTPERFDATA'
2018-03-20 12:23:12 [59690] [1] Found Performance Data for cbm030 / _HOST_ (rta=0.502000ms;3000.000000;5000.000000;0.000000 pl=0%;80;100;0)
2018-03-20 12:23:12 [59691] [2] data2rrd called
2018-03-20 12:23:12 [59690] [2] data2rrd called
2018-03-20 12:23:12 [59691] [2] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_runtime.rrd DATATYPE::SERVICEPERFDATA:0
2018-03-20 12:23:12 [59691] [0] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_runtime.rrd DATATYPE::SERVICEPERFDATA:0
2018-03-20 12:23:12 [59691] [0] RRDs::update ERROR /var/lib/pnp4nagios/.pnp-internal/runtime_runtime.rrd: found extra data on update argument: SERVICEPERFDATA:0
2018-03-20 12:23:12 [59691] [2] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_rows.rrd DATATYPE::SERVICEPERFDATA:0
2018-03-20 12:23:12 [59690] [2] RRDs::update /var/lib/pnp4nagios/cbm030/_HOST_.rrd 1521566571:0.502000:0
2018-03-20 12:23:12 [59691] [0] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_rows.rrd DATATYPE::SERVICEPERFDATA:0


And the other is:
2018-03-20 12:22:40 [59556] [1] process_perfdata.pl-0.6.25 starting in BULK Mode called by NPCD
2018-03-20 12:22:40 [59556] [2] searching for /var/spool/pnp4nagios/host-perfdata.1521566555
2018-03-20 12:22:40 [59556] [2] renaming /var/spool/pnp4nagios/host-perfdata.1521566555 to /var/spool/pnp4nagios/host-perfdata.1521566555-PID-59556 for bulk update
2018-03-20 12:22:40 [59556] [2] reading /var/spool/pnp4nagios/host-perfdata.1521566555-PID-59556 for bulk update
2018-03-20 12:22:40 [59556] [2] Processing Line 1
2018-03-20 12:22:40 [59556] [2] Datatype set to 'HOSTPERFDATA'
2018-03-20 12:22:40 [59556] [1] Found Performance Data for cbm016 / _HOST_ (rta=0.344000ms;3000.000000;5000.000000;0.000000 pl=0%;80;100;0)
2018-03-20 12:22:40 [59556] [2] data2rrd called
2018-03-20 12:22:40 [59556] [2] RRDs::update /var/lib/pnp4nagios/cbm016/_HOST_.rrd 1521566540:0.344000:0
2018-03-20 12:22:40 [59556] [2] /var/lib/pnp4nagios/cbm016/_HOST_.rrd updated
2018-03-20 12:22:40 [59556] [2] Processing Line 2
2018-03-20 12:22:40 [59556] [2] Datatype set to 'HOSTPERFDATA'
2018-03-20 12:22:40 [59556] [1] Found Performance Data for aspe7 / _HOST_ (rta=0.288000ms;3000.000000;5000.000000;0.000000 pl=0%;80;100;0)
2018-03-20 12:22:40 [59556] [2] data2rrd called
2018-03-20 12:22:40 [59556] [2] RRDs::update /var/lib/pnp4nagios/aspe7/_HOST_.rrd 1521566554:0.288000:0
2018-03-20 12:22:40 [59556] [2] /var/lib/pnp4nagios/aspe7/_HOST_.rrd updated
2018-03-20 12:22:40 [59556] [1] 2 lines processed
2018-03-20 12:22:40 [59556] [1] /var/spool/pnp4nagios/host-perfdata.1521566555-PID-59556 deleted
2018-03-20 12:22:40 [59556] [2] data2rrd called
2018-03-20 12:22:40 [59556] [2] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_runtime.rrd 0:0
2018-03-20 12:22:40 [59556] [0] RRDs::update /var/lib/pnp4nagios/.pnp-internal/runtime_runtime.rrd 0:0
2018-03-20 12:22:40 [59556] [0] RRDs::update ERROR /var/lib/pnp4nagios/.pnp-internal/runtime_runtime.rrd: illegal attempt to update using time 0 when last update ti
me is 1521566495 (minimum one second step)

Please let me know if you need anything else.

Thanks,
Dave.

I'm wondering if it's worth trying to move away from the BULK Mode called by NPCD method, although I'm thinking if it's a data issue the method wouldn't make any difference...

I've attached modified process_perfdata.pl file that will copy the perfdata files into /tmp/. Replace the existing one with this file, let it run a bit and when the error pops up in the log, grab the error message as well as the perfdata file it seems to have a problem with. This sounds like it is happening frequently enough where you won't need this to run long - make sure to delete any files this creates in /tmp and reinstate the original process_perfdata.pl after the data's been collected.