Bug #6444
closedMonitoring graphs are down after reboot
0%
Description
Hello.
After I reboot the pfSense VM, all monitoring graphs are down. (Status/Monitoring)
I see the graph, but everything is 0.
After I click on Settings/ Display Advanced/ Reset Graphing Data the Monitoring is back up.
2.3.1-RELEASE-p1 (amd64)
Regards
Lingo
Files
Updated by Chris Buechler about 9 years ago
- Status changed from New to Feedback
is updaterrd.sh running? any rrdtool errors in system log?
Updated by Tom - about 9 years ago
If I type in: ps -axfw | grep updaterrd.sh it is running.
Here are the rrdtool erros from system logs:
Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-mbuf.rrd N:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-mbuf.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-memory.rrd N:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-memory.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-processor.rrd N:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-processor.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-states.rrd N:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-states.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/ovpns1-vpnusers.rrd N:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/ovpns1-vpnusers.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/ovpns1-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/ovpns1-packets.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/ovpns1-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/ovpns1-traffic.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/ipsec-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/ipsec-packets.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/ipsec-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/ipsec-traffic.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt6-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt6-packets.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt6-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt6-traffic.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt5-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt5-packets.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt5-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt5-traffic.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt4-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt4-packets.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt4-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt4-traffic.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt3-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt3-packets.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt3-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt3-traffic.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt1-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt1-packets.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt1-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt1-traffic.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/lan-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/lan-packets.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/lan-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/lan-traffic.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/wan-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/wan-packets.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)' Jun 3 16:15:35 php-cgi rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/wan-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/wan-traffic.rrd: illegal attempt to update using time 1464963335 when last update time is 1465022664 (minimum one second step)'
and btw. I got after every reboot these time errors: (This VM is running Hyper-V (2012R2), I tried to fix fix this error but nothing works)
Jun 3 16:16:39 kernel calcru: runtime went backwards from 69865007 usec to 35316568 usec for pid 0 (kernel) Jun 3 16:16:39 kernel calcru: runtime went backwards from 7 usec to 3 usec for pid 0 (kernel) Jun 3 16:16:39 kernel calcru: runtime went backwards from 13 usec to 6 usec for pid 0 (kernel) Jun 3 16:16:39 kernel calcru: runtime went backwards from 1035 usec to 550 usec for pid 0 (kernel) Jun 3 16:16:39 kernel calcru: runtime went backwards from 11 usec to 5 usec for pid 0 (kernel) Jun 3 16:16:39 kernel calcru: runtime went backwards from 82346 usec to 41625 usec for pid 0 (kernel) Jun 3 16:16:39 kernel calcru: runtime went backwards from 1485 usec to 750 usec for pid 0 (kernel) Jun 3 16:16:39 kernel calcru: runtime went backwards from 84669 usec to 42880 usec for pid 0 (kernel) Jun 3 16:16:39 kernel calcru: runtime went backwards from 6796 usec to 3671 usec for pid 1 (init) Jun 3 16:16:39 kernel calcru: runtime went backwards from 6853242 usec to 3469555 usec for pid 1 (init) Jun 3 16:16:39 kernel calcru: runtime went backwards from 6796 usec to 3671 usec for pid 1 (init) Jun 3 16:16:39 kernel calcru: runtime went backwards from 82 usec to 41 usec for pid 12 (intr) Jun 3 16:16:39 kernel calcru: runtime went backwards from 11 usec to 5 usec for pid 12 (intr) Jun 3 16:16:39 kernel calcru: runtime went backwards from 36820 usec to 34598 usec for pid 12 (intr) Jun 3 16:16:39 kernel calcru: runtime went backwards from 59 usec to 30 usec for pid 12 (intr) Jun 3 16:16:39 kernel calcru: runtime went backwards from 154 usec to 78 usec for pid 12 (intr) Jun 3 16:16:39 kernel calcru: runtime went backwards from 385 usec to 194 usec for pid 13 (ng_queue) Jun 3 16:16:39 kernel calcru: runtime went backwards from 383 usec to 193 usec for pid 13 (ng_queue) Jun 3 16:16:39 kernel calcru: runtime went backwards from 17578 usec to 8885 usec for pid 14 (geom) Jun 3 16:16:39 kernel calcru: runtime went backwards from 550 usec to 278 usec for pid 14 (geom) Jun 3 16:16:39 kernel calcru: runtime went backwards from 3095 usec to 1564 usec for pid 14 (geom) Jun 3 16:16:39 kernel calcru: runtime went backwards from 21135 usec to 10683 usec for pid 14 (geom) Jun 3 16:16:39 kernel calcru: runtime went backwards from 5 usec to 2 usec for pid 2 (crypto) Jun 3 16:16:39 kernel calcru: runtime went backwards from 20 usec to 10 usec for pid 3 (crypto returns) Jun 3 16:16:39 kernel calcru: runtime went backwards from 57753 usec to 31872 usec for pid 4 (cam) Jun 3 16:16:39 kernel calcru: runtime went backwards from 218770 usec to 110587 usec for pid 4 (cam) Jun 3 16:16:39 kernel calcru: runtime went backwards from 56005 usec to 30988 usec for pid 4 (cam) Jun 3 16:16:39 kernel calcru: runtime went backwards from 11062 usec to 5802 usec for pid 5 (fdc0) Jun 3 16:16:39 kernel calcru: runtime went backwards from 10212 usec to 5372 usec for pid 5 (fdc0) Jun 3 16:16:39 kernel calcru: runtime went backwards from 69 usec to 34 usec for pid 7 (sctp_iterator) Jun 3 16:16:39 kernel calcru: runtime went backwards from 67 usec to 34 usec for pid 7 (sctp_iterator) Jun 3 16:16:39 kernel calcru: runtime went backwards from 3517 usec to 2973 usec for pid 18 (bufdaemon) Jun 3 16:16:39 kernel calcru: runtime went backwards from 3583 usec to 3143 usec for pid 18 (bufdaemon) Jun 3 16:16:39 kernel calcru: runtime went backwards from 12161 usec to 6753 usec for pid 51 (md0) Jun 3 16:16:39 kernel calcru: runtime went backwards from 12161 usec to 6753 usec for pid 51 (md0) Jun 3 16:16:39 kernel calcru: runtime went backwards from 5454 usec to 4185 usec for pid 264 (php-fpm) Jun 3 16:16:39 kernel calcru: runtime went backwards from 5454 usec to 4185 usec for pid 264 (php-fpm) Jun 3 16:16:39 kernel calcru: runtime went backwards from 252894 usec to 127837 usec for pid 265 (php-fpm) Jun 3 16:16:39 kernel calcru: runtime went backwards from 53632 usec to 27111 usec for pid 265 (php-fpm) Jun 3 16:16:39 kernel calcru: runtime went backwards from 252894 usec to 127837 usec for pid 265 (php-fpm) Jun 3 16:16:39 kernel calcru: runtime went backwards from 282245 usec to 142674 usec for pid 266 (php-fpm) Jun 3 16:16:39 kernel calcru: runtime went backwards from 45968 usec to 23236 usec for pid 266 (php-fpm) Jun 3 16:16:39 kernel calcru: runtime went backwards from 282245 usec to 142674 usec for pid 266 (php-fpm) Jun 3 16:16:39 kernel calcru: runtime went backwards from 4159 usec to 2102 usec for pid 304 (check_reload_status) Jun 3 16:16:39 kernel calcru: runtime went backwards from 4159 usec to 2102 usec for pid 304 (check_reload_status) Jun 3 16:16:39 kernel calcru: runtime went backwards from 416 usec to 210 usec for pid 306 (check_reload_status) Jun 3 16:16:39 kernel calcru: runtime went backwards from 416 usec to 210 usec for pid 306 (check_reload_status) Jun 3 16:16:39 kernel calcru: runtime went backwards from 1818 usec to 936 usec for pid 319 (devd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 7660 usec to 3872 usec for pid 319 (devd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 1818 usec to 936 usec for pid 319 (devd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 3057 usec to 1545 usec for pid 13483 (xinetd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 3057 usec to 1545 usec for pid 13483 (xinetd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 764 usec to 386 usec for pid 16105 (dpinger) Jun 3 16:16:39 kernel calcru: runtime went backwards from 192 usec to 122 usec for pid 16105 (dpinger) Jun 3 16:16:39 kernel calcru: runtime went backwards from 881 usec to 445 usec for pid 21715 (nginx) Jun 3 16:16:39 kernel calcru: runtime went backwards from 881 usec to 445 usec for pid 21715 (nginx) Jun 3 16:16:39 kernel calcru: runtime went backwards from 1200 usec to 606 usec for pid 22211 (nginx) Jun 3 16:16:39 kernel calcru: runtime went backwards from 1200 usec to 606 usec for pid 22211 (nginx) Jun 3 16:16:39 kernel calcru: runtime went backwards from 3416 usec to 1743 usec for pid 22805 (cron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 3416 usec to 1743 usec for pid 22805 (cron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 87019 usec to 53399 usec for pid 24666 (unbound) Jun 3 16:16:39 kernel calcru: runtime went backwards from 87019 usec to 53399 usec for pid 24666 (unbound) Jun 3 16:16:39 kernel calcru: runtime went backwards from 19754 usec to 13232 usec for pid 25260 (ntpd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 2466 usec to 1246 usec for pid 25260 (ntpd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 22221 usec to 14479 usec for pid 25260 (ntpd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 505 usec to 255 usec for pid 29587 (radvd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 505 usec to 255 usec for pid 29587 (radvd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 5218 usec to 3708 usec for pid 80342 (syslogd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 5218 usec to 3708 usec for pid 80342 (syslogd) Jun 3 16:16:39 kernel calcru: runtime went backwards from 337 usec to 170 usec for pid 91641 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 337 usec to 170 usec for pid 91641 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 157 usec to 79 usec for pid 91822 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 157 usec to 79 usec for pid 91822 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 475 usec to 240 usec for pid 91901 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 475 usec to 240 usec for pid 91901 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 171 usec to 86 usec for pid 92257 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 171 usec to 86 usec for pid 92257 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 347 usec to 175 usec for pid 92577 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 347 usec to 175 usec for pid 92577 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 180 usec to 91 usec for pid 92822 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 180 usec to 91 usec for pid 92822 (minicron) Jun 3 16:16:39 kernel calcru: runtime went backwards from 16 usec to 8 usec for pid 2772 (filterdns) Jun 3 16:16:39 kernel calcru: runtime went backwards from 1300 usec to 1120 usec for pid 2772 (filterdns) Jun 3 16:16:00 kernel calcru: runtime went backwards from 48232 usec to 24381 usec for pid 267 (php-fpm) Jun 3 16:16:00 kernel calcru: runtime went backwards from 102614 usec to 51882 usec for pid 267 (php-fpm)
Thanks.
Regards
Lingo
Updated by Chris Buechler about 9 years ago
- Status changed from Feedback to Not a Bug
- Affected Version deleted (
2.3.1)
your system clock was well into the future at some point. Disable Hyper-V's time sync to get rid of the runtime went backwards. there's something beyond that wrong with your time on the host or guest as well, not a bug.
Updated by Tom - about 9 years ago
Hyper-V time sync is for pfSense VM disabled.
Hyper-V Server and pfSense are both synced with the same ntp servers.
Until now I could'f found why the calcru error happens.
There are also a lot of information on google with this error, but no solution works for me.
Any idea?
Updated by Chris Buechler about 9 years ago
the "runtime went backwards" is just log spam, but it was annoying me, and I tracked down where it was fixed in newer FreeBSD versions. Merged that fix in #6446 for 2.3.2.
Unrelated to your issue though, which is that the system was running with a date of 04 June 2016 06:44 at some point before 03 June 16:16.
Please post to forum.pfsense.org if you'd like to discuss further.