Oddness of Traffic Status, RRD Sumary and NTP...

provels

Peculiar images attached. 2.5.2
Today is 2/12/22 - 0630 CST
Status/Monitoring shows wrong date - 2/21/21 - 1017.
Dashboard show correct date/time and NTP status.
RRD Summary died on 2/4.
WTH
FW is a VM on Win 2012R2, VM time sync NOT managed by host.
FW had been rebuilt fresh with restored config a couple months ago.
Any replies appreciated and thanks for reading...

stephenw10

Hmm, weird. Is it updating at the 21st end of that graph?

I have seen some odd graphs when the RRD files have data from a bad system clock.

Steve

provels

@stephenw10 said in Oddness of Traffic Status, RRD Sumary and NTP...:

Hmm, weird. Is it updating at the 21st end of that graph?

I have seen some odd graphs when the RRD files have data from a bad system clock.

Steve

Thank for mentioning that. No, it's stopped @ 1017, 2/12/22. Also, the RRD Summary usage is far below my actual so it's all completely wonky. Main reason I rebuilt it was that NTP didn't want to connect to the pools at reboot; I had to bounce it afterwards. Using pools 1/2/3/4.us.pool.ntp.org. Seems to start OK now, and I was thinking that maybe it didn't connect because Unbound was still in startup mode (using PFBNGdevel) after NTP had already started.

Here's a clip from the system log. WTH.

Feb  4 10:50:06 fw kernel: arp: 00:90:fb:14:06:69 is using my IP address 192.168.0.1 on hn0!
Feb  4 10:50:07 fw kernel: arp: 00:90:fb:14:06:69 is using my IP address 192.168.0.1 on hn0!
Feb  4 10:50:29 fw kernel: hvshutdown0: shutdown requested
Feb  4 10:50:31 fw syslogd: exiting on signal 15
Feb 21 09:19:00 fw syslogd: kernel boot file is /boot/kernel/kernel
Feb 21 09:19:00 fw kernel: ---<<BOOT>>---
Feb 21 09:19:00 fw kernel: Copyright (c) 1992-2020 The FreeBSD Project.
Feb 21 09:19:00 fw kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994

Huh?

Feb 21 09:20:56 fw shutdown[86871]: power-down by root: 
Feb 21 09:20:56 fw syslogd: exiting on signal 15
Feb 21 09:26:27 fw syslogd: kernel boot file is /boot/kernel/kernel
Feb 21 09:26:27 fw kernel: ---<<BOOT>>---
Feb 21 09:26:27 fw kernel: Copyright (c) 1992-2020 The FreeBSD Project.
Feb 21 09:26:27 fw kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994

Um...

Feb 21 10:13:25 fw upsd[76598]: User local-monitor@::1 logged into UPS [APCBR800]
Feb 21 10:13:25 fw upsmon[69010]: Communications with UPS APCBR800 established
Feb 21 10:13:25 fw php[58541]: nut_email.php: Could not send the message to xxx@xxx.xxx -- Error: Failed to connect to smtp.xxx.net:587 [SMTP: Failed to connect socket: php_network_getaddresses: getaddrinfo failed: Name does not resolve (code: -1, response: )]
Feb  5 17:46:39 fw kernel: hvtimesync0: <Hyper-V Timesync> on vmbus0
Feb  5 17:47:18 fw php-fpm[343]: /status_services.php: NTPD is starting up.
Feb  5 17:47:34 fw php-fpm[343]: /status_services.php: NTPD is starting up.
Feb  5 17:47:42 fw upsd[76598]: Data for UPS [APCBR800] is stale - check driver
Feb  5 17:47:47 fw upsmon[69010]: Poll UPS [APCBR800] failed - Data stale

Pretty sure I don't want the host to manage the VM's time when the host is looking to the FW's NTP. Could it be Service Watchdog?

Here's a random RRD/NTP error entry. Makes sense.

Jan 20 01:12:36 fw php[391]: rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/ntpd.rrd N:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/ntpd.rrd: illegal attempt to update using time 1642662756 when last update time is 1642955495 (minimum one second step)'

Here's a sanitized copy of the system.log.

system.txt

Just scrolling the dates I see buckets of problems. It's all NTP.

Again, thanks for your reply and if you see anything pertinent please write back.

bingo600

I'm not a Hyper-V guru
But to me it seems that pfSense (NTP) & Hyper-V is both trying to sync the VM's time.

You are stepping time backwards on the Hyper-V Timesync line.

Feb 21 10:13:25 fw php[58541]: nut_email.php: Could not send the message to xxx@xxx.xxx -- Error: Failed to connect to smtp.xxx.net:587 [SMTP: Failed to connect socket: php_network_getaddresses: getaddrinfo failed: Name does not resolve (code: -1, response: )]
Feb  5 17:46:39 fw kernel: hvtimesync0: <Hyper-V Timesync> on vmbus0
Feb  5 17:47:18 fw php-fpm[343]: /status_services.php: NTPD is starting up.
Feb  5 17:47:34 fw php-fpm[343]: /status_services.php: NTPD is starting up.

NTP won't sync to any peers if the clock is off by more than approx. 20min.
So pfSense NTP will not correct the backwards leap.

I think i read somewhere that you have to make a decision when using VM and timesync.

Either Host sets the time via NTP, or Host gets time from the hypervisor.
Both is a bad idea ...

Just my 2cent of "outside perspective"

The feb-5 date/time , where does that come from ??
Is your PC's HW clock maybe way off , or is the hypervisor ?

Or is it just Bill G again

/Bingo

provels

@bingo600 said in Oddness of Traffic Status, RRD Sumary and NTP...:

I think i read somewhere that you have to make a decision when using VM and timesync.
Either Host sets the time via NTP, or Host gets time from the hypervisor.
Both is a bad idea ...

Yeah, I realize that, but time service from the host is disabled. This may be entirely self-inflicted, but I've had similar RDD problems for a while.

At any rate, thanks for your thoughts. I'll keep digging, it's not a showstopper.
Maybe my RTC on the host has finally died, but I don't think that should matter. PFS looks to NTP, host (and other VMs) look to PFS. I'll be back.

stephenw10

Yeah, this seems like a virtualisation issue. I don't use hyper-v so I can't comment specifically. But if this is not a new issue maybe try enabling time sync there?

Steve

provels

@stephenw10
Thanks. I will, and I think I've read that host time sync is only for maintaining the VMs time when the VM is off, but conversely it doesn't seem the host should loop with the VMs NTP either. I'll give it a try and delete all the present RRD data since it's corrupt anyway. Thanks again.