Not receiving performance graphs

[dLans]

Good afternoon!

After a reboot of the Nagios XI server we are no longer able to see any data on our performance graphs. It says "No data to display". I have tried several troubleshooting steps myself and found several issues:

- The system time was set to 11 may 2017. I used "ntpdate <ip address>" to sync the time with our domain controller.

Code: Select all

20 Apr 17:19:00 ntpdate[8244]: step time server x.x.x.x offset -1991168.028776 sec

- The directory /var/lock/mrtg was missing. I've manually recreated it and the current permissions are set as follows:

Code: Select all

ll /var/lock/
drwxr-xr-x 2 root root  40 Apr 20 13:50 mrtg

Some log file checks (where you can clearly see the time jump to 11-05-2017):

Code: Select all

# tail -75 /usr/local/nagios/var/npcd.log

[03-26-2017 14:20:19] NPCD: Caught Termination Signal - Hasta la vista... baby
[03-26-2017 16:37:42] NPCD: npcd Daemon (0.4.14) started with PID=1006
[03-26-2017 16:37:42] NPCD: Please have a look at 'npcd -V' to get license information
[03-26-2017 16:37:42] NPCD: HINT: load_threshold is enabled - ('10.000000')
[04-18-2017 17:51:14] NPCD: Caught Termination Signal - Hasta la vista... baby
[05-11-2017 18:58:01] NPCD: npcd Daemon (0.4.14) started with PID=1002
[05-11-2017 18:58:01] NPCD: Please have a look at 'npcd -V' to get license information
[05-11-2017 18:58:01] NPCD: HINT: load_threshold is enabled - ('10.000000')
[04-20-2017 16:09:52] NPCD: Caught Termination Signal - Hasta la vista... baby
[04-20-2017 16:09:52] NPCD: npcd Daemon (0.4.14) started with PID=21932
[04-20-2017 16:09:52] NPCD: Please have a look at 'npcd -V' to get license information
[04-20-2017 16:09:52] NPCD: HINT: load_threshold is enabled - ('10.000000')
[04-20-2017 16:42:01] NPCD: Caught Termination Signal - Hasta la vista... baby
[04-20-2017 16:42:01] NPCD: npcd Daemon (0.4.14) started with PID=61062
[04-20-2017 16:42:01] NPCD: Please have a look at 'npcd -V' to get license information
[04-20-2017 16:42:01] NPCD: HINT: load_threshold is enabled - ('10.000000')
[04-20-2017 16:42:13] NPCD: Caught Termination Signal - Hasta la vista... baby
[04-20-2017 16:42:13] NPCD: npcd Daemon (0.4.14) started with PID=61244
[04-20-2017 16:42:13] NPCD: Please have a look at 'npcd -V' to get license information
[04-20-2017 16:42:13] NPCD: HINT: load_threshold is enabled - ('10.000000')
[04-20-2017 16:46:26] NPCD: Caught Termination Signal - Hasta la vista... baby
[04-20-2017 16:46:26] NPCD: npcd Daemon (0.4.14) started with PID=1411
[04-20-2017 16:46:26] NPCD: Please have a look at 'npcd -V' to get license information
[04-20-2017 16:46:26] NPCD: HINT: load_threshold is enabled - ('10.000000')
[04-20-2017 16:48:21] NPCD: npcd Daemon (0.4.14) started with PID=3348
[04-20-2017 16:48:21] NPCD: Please have a look at 'npcd -V' to get license information
[04-20-2017 16:48:21] NPCD: HINT: load_threshold is enabled - ('10.000000')
[04-20-2017 16:59:37] NPCD: Caught Termination Signal - Hasta la vista... baby
[04-20-2017 16:59:37] NPCD: npcd Daemon (0.4.14) started with PID=18070
[04-20-2017 16:59:37] NPCD: Please have a look at 'npcd -V' to get license information
[04-20-2017 16:59:37] NPCD: HINT: load_threshold is enabled - ('10.000000')
[04-20-2017 17:01:45] NPCD: Caught Termination Signal - Hasta la vista... baby
[04-20-2017 17:01:45] NPCD: npcd Daemon (0.4.14) started with PID=20506
[04-20-2017 17:01:45] NPCD: Please have a look at 'npcd -V' to get license information
[04-20-2017 17:01:45] NPCD: HINT: load_threshold is enabled - ('10.000000')

Code: Select all

# tail -f /usr/local/nagios/var/perfdata.log

2016-06-20 17:25:43 [59268] [0] *** TIMEOUT: Please check your npcd.cfg
2016-06-20 17:25:43 [59268] [0] *** TIMEOUT: /usr/local/nagios/var/spool/perfdata//1466436330.perfdata.host-PID-59268 deleted
2016-06-20 17:25:43 [59268] [0] *** Timeout while processing Host: "nloospr1.dbgroup.local" Service: "_HOST_"
2016-06-20 17:25:43 [59268] [0] *** process_perfdata.pl terminated on signal ALRM
2016-06-21 19:12:01 [20078] [0] *** TIMEOUT: Timeout after 5 secs. ***
2016-06-21 19:12:01 [20078] [0] *** TIMEOUT: Deleting current file to avoid NPCD loops
2016-06-21 19:12:01 [20078] [0] *** TIMEOUT: Please check your npcd.cfg
2016-06-21 19:12:01 [20078] [0] *** TIMEOUT: /usr/local/nagios/var/spool/perfdata//1466529105.perfdata.service-PID-20078 deleted
2016-06-21 19:12:01 [20078] [0] *** Timeout while processing Host: "nloosvmm.dbgroup.local" Service: "F_Schijf"
2016-06-21 19:12:01 [20078] [0] *** process_perfdata.pl terminated on signal ALRM

- Then I found that the npcd service cannot read the PID file:

Code: Select all

# systemctl status npcd
● npcd.service - SYSV: Visit the Website at http://sourceforge.net/projects/pnp4nagios/
   Loaded: loaded (/etc/rc.d/init.d/npcd; bad; vendor preset: disabled)
   Active: active (running) since Thu 2017-04-20 16:48:21 CEST; 14s ago
     Docs: man:systemd-sysv-generator(8)
  Process: 1401 ExecStop=/etc/rc.d/init.d/npcd stop (code=exited, status=0/SUCCESS)
  Process: 3345 ExecStart=/etc/rc.d/init.d/npcd start (code=exited, status=0/SUCCESS)
 Main PID: 3348 (npcd)
   CGroup: /system.slice/npcd.service
           ├─1411 /usr/local/nagios/bin/npcd -d -f /usr/local/nagios/etc/pnp/npcd.cfg
           └─3348 /usr/local/nagios/bin/npcd -d -f /usr/local/nagios/etc/pnp/npcd.cfg

Apr 20 16:48:21 nlgrpngs.dbgroup.local systemd[1]: Starting SYSV: Visit the Website at http://sourceforge.net/projects/pnp4nagios/...
Apr 20 16:48:21 nlgrpngs.dbgroup.local npcd[3345]: NPCD started.
Apr 20 16:48:21 nlgrpngs.dbgroup.local systemd[1]: Failed to read PID from file /usr/local/nagiosxi/var/subsys/npcd.pid: Invalid argument
Apr 20 16:48:21 nlgrpngs.dbgroup.local systemd[1]: Started SYSV: Visit the Website at http://sourceforge.net/projects/pnp4nagios/.

The PID file does exist with the following permissions set:

Code: Select all

]# ll /usr/local/nagiosxi/var/subsys/
total 8
-rw-r--r-- 1 root   root   0 Apr 20 15:42 nagios
-rw-r--r-- 1 nagios nagios 0 Dec 11 15:14 ndo2db
-rw-r--r-- 1 root   root   4 Apr 20 16:48 npcd.pid

I tried adjusting the permissions to nagios nagios but after a npcd service restart it automatically sets it back to root root so I'm guesing that is as it should be. So the current problem seems to have something to do with the PID file and are most likely caused by the time sync issues. I've tried restarting our SQL, Nagios, NDO2DB, NPCD & HTTPD services. I also just noticed that we cannot perform actions such as "apply configuration". We get an error message when using "force an immediate check" saying that the request was not processed in a timely manner. However, the check is still being executed instantly.

Any suggestions?

Kind regards,
Dennis Lans

[dwhitfield]

What's the output of the following:

Code: Select all

hwclock
grep date.timezone /etc/php.ini
date
echo "SELECT CURRENT_TIME;" | mysql -uroot -pnagiosxi

Also, what timezone is the Nagios UI set to?

[dLans]

# hwclock

Code: Select all

Sun 14 May 2017 11:42:43 AM CEST  -1.042645 seconds

So I ran:

Code: Select all

# hwclock --systohc

And now it is correct
# hwclock

Code: Select all

Fri 21 Apr 2017 10:38:41 AM CEST  -1.042343 seconds

# grep date.timezone /etc/php.ini

Code: Select all

; http://php.net/date.timezone
date.timezone = Europe/Amsterdam

# date

Code: Select all

Fri Apr 21 10:40:09 CEST 2017

# echo "SELECT CURRENT_TIME;" | mysql -uroot -p**********

Code: Select all

CURRENT_TIME
10:41:48

I rebooted the system after the hwclock change to make sure it stayed correct, and it is. After the reboot I noticed the directory /var/lock/mrtg was missing again, I've recreated it manually. Restarted the npcd & crond services. I waited about 10 minutes after the reboot to see if any data was being shown in the graphs, but unfortunately not yet.

# systemctl status npcd

Code: Select all

● npcd.service - SYSV: Visit the Website at http://sourceforge.net/projects/pnp4nagios/
   Loaded: loaded (/etc/rc.d/init.d/npcd; bad; vendor preset: disabled)
   Active: active (running) since Fri 2017-04-21 10:47:12 CEST; 2min 7s ago
     Docs: man:systemd-sysv-generator(8)
  Process: 6859 ExecStop=/etc/rc.d/init.d/npcd stop (code=exited, status=0/SUCCESS)
  Process: 6866 ExecStart=/etc/rc.d/init.d/npcd start (code=exited, status=0/SUCCESS)
 Main PID: 6869 (npcd)
   CGroup: /system.slice/npcd.service
           └─6869 /usr/local/nagios/bin/npcd -d -f /usr/local/nagios/etc/pnp/npcd.cfg

Apr 21 10:47:12 nlgrpngs.dbgroup.local systemd[1]: Starting SYSV: Visit the Website at http://sourceforge.net/projects/pnp4nagios/...
Apr 21 10:47:12 nlgrpngs.dbgroup.local npcd[6866]: NPCD started.
Apr 21 10:47:12 nlgrpngs.dbgroup.local systemd[1]: Failed to read PID from file /usr/local/nagiosxi/var/subsys/npcd.pid: Invalid argument
Apr 21 10:47:12 nlgrpngs.dbgroup.local systemd[1]: Started SYSV: Visit the Website at http://sourceforge.net/projects/pnp4nagios/.

The PID file is definitely on location:
-rw-r--r-- 1 root root 4 Apr 21 10:47 npcd.pid

Nagios UI timezone is set to UTC +1, Amsterdam.

I am sorry for bothering you with something that was clearly caused by a RHEL/Hyper-V issue.

Kind regards,
Dennis Lans

[dLans]

# ps -aef | grep npcd

Code: Select all

nagios   20901     1  0 11:00 ?        00:00:00 /usr/local/nagios/bin/npcd -d -f /usr/local/nagios/etc/pnp/npcd.cfg
root     21035  3092  0 11:00 pts/0    00:00:00 grep --color=auto npcd

Does the above mean there are two npcd services running? Could that possible cause the problems with the PID file (if one of the processes takes "ownership")?

[dLans]

After setting it to debugging I get the message "is an already in process PNP file":

# tail -50 /usr/local/nagios/var/npcd.log

Code: Select all

[04-21-2017 11:09:36] NPCD: DEBUG: load 0.210000/10.000000
[04-21-2017 11:09:36] NPCD: ThreadCounter 2/5 File is 1492765769.perfdata.host
[04-21-2017 11:09:36] NPCD: Processing file '1492765754.perfdata.service'
[04-21-2017 11:09:36] NPCD: Regular File: 1492765769.perfdata.host
[04-21-2017 11:09:36] NPCD: A thread was started on thread_counter = 2
[04-21-2017 11:09:36] NPCD: Processing file 1492765769.perfdata.host with ID 139983968188160 - going to exec /usr/loc
[04-21-2017 11:09:36] NPCD: DEBUG: load 0.210000/10.000000
[04-21-2017 11:09:36] NPCD: Processing file '1492765769.perfdata.host'
[04-21-2017 11:09:36] NPCD: ThreadCounter 3/5 File is 1492765769.perfdata.service
[04-21-2017 11:09:36] NPCD: Regular File: 1492765769.perfdata.service
[04-21-2017 11:09:36] NPCD: A thread was started on thread_counter = 3
[04-21-2017 11:09:36] NPCD: Have to wait: Filecounter = 5 - thread_counter = 4
[04-21-2017 11:09:36] NPCD: Processing file 1492765769.perfdata.service with ID 139983959795456 - going to exec /usr/
[04-21-2017 11:09:36] NPCD: Processing file '1492765769.perfdata.service'
[04-21-2017 11:09:38] NPCD: No more files to process... waiting for 15 seconds
[04-21-2017 11:09:45] NPCD: Caught Termination Signal - Hasta la vista... baby
[04-21-2017 11:09:45] NPCD: npcd Daemon (0.4.14) started with PID=30247
[04-21-2017 11:09:45] NPCD: Please have a look at 'npcd -V' to get license information
[04-21-2017 11:09:45] NPCD: HINT: load_threshold is enabled - ('10.000000')
[04-21-2017 11:09:45] NPCD: Found 3 files in /usr/local/nagios/var/spool/perfdata/
[04-21-2017 11:09:45] NPCD: DEBUG: load 0.260000/10.000000
[04-21-2017 11:09:45] NPCD: ThreadCounter 0/5 File is .
[04-21-2017 11:09:45] NPCD: DEBUG: load 0.260000/10.000000
[04-21-2017 11:09:45] NPCD: ThreadCounter 0/5 File is ..
[04-21-2017 11:09:45] NPCD: DEBUG: load 0.260000/10.000000
[04-21-2017 11:09:45] NPCD: ThreadCounter 0/5 File is 1484831671.perfdata.host-PID-38725
[04-21-2017 11:09:45] NPCD: File '1484831671.perfdata.host-PID-38725' is an already in process PNP file. Leaving it u
[04-21-2017 11:09:45] NPCD: No more files to process... waiting for 15 seconds
[04-21-2017 11:10:00] NPCD: Found 5 files in /usr/local/nagios/var/spool/perfdata/
[04-21-2017 11:10:00] NPCD: DEBUG: load 0.200000/10.000000
[04-21-2017 11:10:00] NPCD: ThreadCounter 0/5 File is .
[04-21-2017 11:10:00] NPCD: DEBUG: load 0.200000/10.000000
[04-21-2017 11:10:00] NPCD: ThreadCounter 0/5 File is ..
[04-21-2017 11:10:00] NPCD: DEBUG: load 0.200000/10.000000
[04-21-2017 11:10:00] NPCD: ThreadCounter 0/5 File is 1484831671.perfdata.host-PID-38725
[04-21-2017 11:10:00] NPCD: File '1484831671.perfdata.host-PID-38725' is an already in process PNP file. Leaving it u
[04-21-2017 11:10:00] NPCD: DEBUG: load 0.200000/10.000000
[04-21-2017 11:10:00] NPCD: ThreadCounter 0/5 File is 1492765784.perfdata.host
[04-21-2017 11:10:00] NPCD: Regular File: 1492765784.perfdata.host
[04-21-2017 11:10:00] NPCD: A thread was started on thread_counter = 0
[04-21-2017 11:10:00] NPCD: DEBUG: load 0.200000/10.000000
[04-21-2017 11:10:00] NPCD: ThreadCounter 1/5 File is 1492765784.perfdata.service
[04-21-2017 11:10:00] NPCD: Processing file 1492765784.perfdata.host with ID 139662778054400 - going to exec /usr/loc
[04-21-2017 11:10:00] NPCD: Regular File: 1492765784.perfdata.service
[04-21-2017 11:10:00] NPCD: Processing file '1492765784.perfdata.host'
[04-21-2017 11:10:00] NPCD: A thread was started on thread_counter = 1
[04-21-2017 11:10:00] NPCD: Processing file 1492765784.perfdata.service with ID 139662769661696 - going to exec /usr/
[04-21-2017 11:10:00] NPCD: Have to wait: Filecounter = 3 - thread_counter = 2
[04-21-2017 11:10:00] NPCD: Processing file '1492765784.perfdata.service'
[04-21-2017 11:10:02] NPCD: No more files to process... waiting for 15 seconds

# ll

Code: Select all

-rw-r--r-- 1 nagios nagios 9935 Jan 19 14:14 1484831671.perfdata.host-PID-38725

[dwhitfield]

# ps -aef | grep npcd

Code: Select all

nagios   20901     1  0 11:00 ?        00:00:00 /usr/local/nagios/bin/npcd -d -f /usr/local/nagios/etc/pnp/npcd.cfg
root     21035  3092  0 11:00 pts/0    00:00:00 grep --color=auto npcd

Does the above mean there are two npcd services running? Could that possible cause the problems with the PID file (if one of the processes takes "ownership")?

No, one is the binary and the other is the config file. The grep line is just the grep you just ran.

Please take a look at https://support.nagios.com/kb/article.php?id=9. You've already covered some of it, but I haven't seen any info here about the spool directories. You may have done it, but we'd like to verify. Thanks!

[dLans]

Hi dwhitfield,

Thank you for your reply. With the command listed on the page I've found an error in the perfdata.log, releated to our time issue.

# tail -f /usr/local/nagios/var/perfdata.log

Code: Select all

2017-04-24 08:05:01 [43708] [2] RRDs::update /usr/local/nagios/share/perfdata/nlgrpbhv02.dbgroup.local/C__Disk_usage.rrd 1493013885:66:63.056
2017-04-24 08:05:01 [43708] [1] RRDs::update ERROR /usr/local/nagios/share/perfdata/nlgrpbhv02.dbgroup.local/C__Disk_usage.rrd: illegal attempt to update using time 1493013885 when last update time is 1494692678 (minimum one second step)
2017-04-24

# date

Code: Select all

Mon Apr 24 08:07:47 CEST 2017

# hwclock

Code: Select all

Mon 24 Apr 2017 08:08:19 AM CEST  -1.041761 seconds

Both of the above is correctly set (thanks to your earlier suggestion). The server had a reboot after the system time changed, so I'm not sure what I should be doing next.

Kind regards,
Dennis Lans



The other commands that I performed from that page, but that do not show problems imo (still posting, you never know^^):

Code: Select all

# ls /usr/local/nagios/var/spool/perfdata/ | wc -l
3

Code: Select all

# ls /usr/local/nagios/var/spool/xidpe/ | wc -l
0

Code: Select all

[04-24-2017 08:13:06] NPCD: DEBUG: load 0.000000/20.000000
[04-24-2017 08:13:06] NPCD: ThreadCounter 0/5 File is .
[04-24-2017 08:13:06] NPCD: DEBUG: load 0.000000/20.000000
[04-24-2017 08:13:06] NPCD: ThreadCounter 0/5 File is ..
[04-24-2017 08:13:06] NPCD: DEBUG: load 0.000000/20.000000
[04-24-2017 08:13:06] NPCD: ThreadCounter 0/5 File is 1484831671.perfdata.host-PID-38725
[04-24-2017 08:13:06] NPCD: File '1484831671.perfdata.host-PID-38725' is an already in process PNP file. Leaving it untouched.
[04-24-2017 08:13:06] NPCD: DEBUG: load 0.000000/20.000000
[04-24-2017 08:13:06] NPCD: ThreadCounter 0/5 File is 1493014365.perfdata.host
[04-24-2017 08:13:06] NPCD: Regular File: 1493014365.perfdata.host
[04-24-2017 08:13:06] NPCD: A thread was started on thread_counter = 0
[04-24-2017 08:13:06] NPCD: Processing file 1493014365.perfdata.host with ID 140652122724096 - going to exec /usr/local/nagios/libexec/process_perfdata.pl -n -b /usr/local/nagios/var/spool/perfdata//1493014365.perfdata.host
[04-24-2017 08:13:06] NPCD: Processing file '1493014365.perfdata.host'
[04-24-2017 08:13:06] NPCD: DEBUG: load 0.000000/20.000000
[04-24-2017 08:13:06] NPCD: ThreadCounter 1/5 File is 1493014365.perfdata.service
[04-24-2017 08:13:06] NPCD: Regular File: 1493014365.perfdata.service
[04-24-2017 08:13:06] NPCD: A thread was started on thread_counter = 1
[04-24-2017 08:13:06] NPCD: DEBUG: load 0.000000/20.000000
[04-24-2017 08:13:06] NPCD: Processing file 1493014365.perfdata.service with ID 140652114331392 - going to exec /usr/local/nagios/libexec/process_perfdata.pl -n -b /usr/local/nagios/var/spool/perfdata//1493014365.perfdata.service
[04-24-2017 08:13:06] NPCD: ThreadCounter 2/5 File is 1493014380.perfdata.host
[04-24-2017 08:13:06] NPCD: Processing file '1493014365.perfdata.service'
[04-24-2017 08:13:06] NPCD: Regular File: 1493014380.perfdata.host
[04-24-2017 08:13:06] NPCD: A thread was started on thread_counter = 2
[04-24-2017 08:13:06] NPCD: DEBUG: load 0.000000/20.000000
[04-24-2017 08:13:06] NPCD: ThreadCounter 3/5 File is 1493014380.perfdata.service
[04-24-2017 08:13:06] NPCD: Regular File: 1493014380.perfdata.service
[04-24-2017 08:13:06] NPCD: A thread was started on thread_counter = 3
[04-24-2017 08:13:06] NPCD: Have to wait: Filecounter = 5 - thread_counter = 4
[04-24-2017 08:13:06] NPCD: Processing file 1493014380.perfdata.host with ID 140652103751424 - going to exec /usr/local/nagios/libexec/process_perfdata.pl -n -b /usr/local/nagios/var/spool/perfdata//1493014380.perfdata.host
[04-24-2017 08:13:06] NPCD: Processing file '1493014380.perfdata.host'
[04-24-2017 08:13:06] NPCD: Processing file 1493014380.perfdata.service with ID 140652095358720 - going to exec /usr/local/nagios/libexec/process_perfdata.pl -n -b /usr/local/nagios/var/spool/perfdata//1493014380.perfdata.service
[04-24-2017 08:13:06] NPCD: Processing file '1493014380.perfdata.service'
[04-24-2017 08:13:08] NPCD: No more files to process... waiting for 15 seconds

[dwhitfield]

What's the output of the following?

Code: Select all

ll /usr/local/nagios/libexec/process_perfdata.pl
ll /usr/local/pnp4nagios/var/host-perfdata
ll /usr/local/pnp4nagios/var/service-perfdata

Also, can you PM me your Profile? You can download it by going to Admin > System Config > System Profile and click the Download Profile button towards the top. If for whatever reason you *cannot* download the profile, please put the output of View System Info (5.3.4+, Show Profile if older) in the thread (that will at least get us some info). This will give us access to many of the logs we would otherwise ask for individually. If security is a concern, you can unzip the profile take out what you like, and then zip it up again. We may end up needing something you remove, but we can ask for that specifically.

After you PM the profile, please update this thread. Updating this thread is the only way for it to show back up on our dashboard.

[dLans]

# ll /usr/local/nagios/libexec/process_perfdata.pl

Code: Select all

-rwxrwxr-x 1 apache nagios 42803 Nov 27 18:27 /usr/local/nagios/libexec/process_perfdata.pl

# ll /usr/local/pnp4nagios/var/host-perfdata

Code: Select all

ls: cannot access /usr/local/pnp4nagios/var/host-perfdata: No such file or directory

# ll /usr/local/pnp4nagios/var/service-perfdata

Code: Select all

ls: cannot access /usr/local/pnp4nagios/var/service-perfdata: No such file or directory

I've send you the profile. Thank you for the time and effort, it is much appreciated!

Kind regards,
Dennis Lans

[dwhitfield]

Looks like yours are in a different location, probably the following:

Code: Select all

ll /usr/local/nagios/var/host-perfdata
ll /usr/local/nagios/var/service-perfdata

If not, try find / -name host-perfdata and service-perfdata is probably in the same directory.

UPDATE: profile received and shared with techs