Calcru: runtime went backwards from 345 usec to 174 usec [solved]
-
I know this has been discussed before but I'm wondering what the latest news is on the cause and solution for these errors that I still get in 2.2. Is someone working on an official fix?
Sep 9 17:28:33 kernel: calcru: runtime went backwards from 65155365 usec to 32942848 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 16 usec to 8 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 890 usec to 450 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 5 usec to 2 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 5 usec to 2 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 1974 usec to 1031 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 5 usec to 2 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 613 usec to 310 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 9 usec to 4 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 1298 usec to 656 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 2047 usec to 1035 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 1316 usec to 665 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 1257 usec to 635 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 1217 usec to 615 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 2064 usec to 1043 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 1409 usec to 712 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 2370 usec to 1198 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 2789 usec to 1410 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 1751 usec to 885 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 1787 usec to 903 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 2680 usec to 1355 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 2972 usec to 1503 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 2225 usec to 1247 usec for pid 0 (kernel) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 6 usec to 3 usec for pid 10 (audit) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 12481 usec to 6353 usec for pid 1 (init) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 295 usec to 149 usec for pid 12 (intr) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 123 usec to 62 usec for pid 12 (intr) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 155 usec to 78 usec for pid 12 (intr) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 108 usec to 54 usec for pid 12 (intr) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 369 usec to 186 usec for pid 12 (intr) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 218887 usec to 142637 usec for pid 12 (intr) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 82 usec to 41 usec for pid 13 (ng_queue) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 30 usec to 15 usec for pid 13 (ng_queue) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 25111 usec to 12696 usec for pid 14 (geom) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 570 usec to 288 usec for pid 14 (geom) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 2858 usec to 1445 usec for pid 14 (geom) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 5 usec to 2 usec for pid 2 (crypto) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 6 usec to 3 usec for pid 3 (crypto returns) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 135517 usec to 73443 usec for pid 4 (cam) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 211669 usec to 107020 usec for pid 4 (cam) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 14458 usec to 7467 usec for pid 5 (fdc0) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 71 usec to 36 usec for pid 7 (sctp_iterator) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 73582 usec to 38500 usec for pid 56 (md0) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 12208 usec to 7513 usec for pid 243 (php-fpm) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 34901486 usec to 20959957 usec for pid 259 (check_reload_status) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 345 usec to 174 usec for pid 261 (check_reload_status) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 1891 usec to 971 usec for pid 270 (devd) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 31734 usec to 22814 usec for pid 4975 (syslogd) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 1742 usec to 1308 usec for pid 9422 (openvpn) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 178893 usec to 90448 usec for pid 9944 (inetd) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 5605 usec to 3157 usec for pid 14275 (rrdtool) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 113026 usec to 57146 usec for pid 15661 (php-fpm) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 113379 usec to 67163 usec for pid 62518 (bsnmpd) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 15227 usec to 14964 usec for pid 65007 (sh) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 3362 usec to 1762 usec for pid 74499 (cron) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 586 usec to 296 usec for pid 75368 (minicron) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 303 usec to 153 usec for pid 75674 (minicron) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 631 usec to 319 usec for pid 76001 (minicron) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 576 usec to 291 usec for pid 76351 (minicron) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 277 usec to 140 usec for pid 76499 (minicron) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 341 usec to 172 usec for pid 76881 (minicron) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 14536 usec to 7349 usec for pid 85540 (login) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 6246 usec to 3158 usec for pid 85575 (sshlockout_pf) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 80 usec to 40 usec for pid 85575 (sshlockout_pf) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 7656 usec to 3871 usec for pid 85797 (sh) Sep 9 17:28:33 kernel: calcru: runtime went backwards from 3475 usec to 2759 usec for pid 86015 (sh) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 5381 usec to 2855 usec for pid 0 (kernel) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 6239748 usec to 3167043 usec for pid 1 (init) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 12481 usec to 6353 usec for pid 1 (init) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 300200 usec to 204924 usec for pid 12 (intr) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 101 usec to 51 usec for pid 13 (ng_queue) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 28272 usec to 14294 usec for pid 14 (geom) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 19768 usec to 16096 usec for pid 15 (rand_harvestq) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 132903 usec to 71135 usec for pid 4 (cam) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 6246 usec to 3238 usec for pid 5 (fdc0) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 68 usec to 34 usec for pid 7 (sctp_iterator) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 2371 usec to 1809 usec for pid 8 (pagedaemon) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 67 usec to 58 usec for pid 17 (idlepoll) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 289 usec to 263 usec for pid 18 (bufdaemon) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 285 usec to 263 usec for pid 20 (vnlru) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 73582 usec to 38072 usec for pid 56 (md0) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 1540645 usec to 778955 usec for pid 243 (php-fpm) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 12353 usec to 7026 usec for pid 243 (php-fpm) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 41177424 usec to 20959957 usec for pid 259 (check_reload_status) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 345 usec to 174 usec for pid 261 (check_reload_status) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 1891 usec to 956 usec for pid 270 (devd) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 32227 usec to 19912 usec for pid 4975 (syslogd) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 1742 usec to 962 usec for pid 9422 (openvpn) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 178893 usec to 90448 usec for pid 9944 (inetd) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 7940 usec to 7488 usec for pid 14151 (apinger) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 5605 usec to 2834 usec for pid 14275 (rrdtool) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 16242 usec to 8212 usec for pid 15661 (php-fpm) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 113026 usec to 57146 usec for pid 15661 (php-fpm) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 115838 usec to 62696 usec for pid 62518 (bsnmpd) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 329430 usec to 166561 usec for pid 65007 (sh) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 16755 usec to 8471 usec for pid 65007 (sh) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 3362 usec to 1762 usec for pid 74499 (cron) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 586 usec to 296 usec for pid 75368 (minicron) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 303 usec to 153 usec for pid 75674 (minicron) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 631 usec to 319 usec for pid 76001 (minicron) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 576 usec to 291 usec for pid 76351 (minicron) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 277 usec to 140 usec for pid 76499 (minicron) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 341 usec to 172 usec for pid 76881 (minicron) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 14536 usec to 7349 usec for pid 85540 (login) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 6326 usec to 3198 usec for pid 85575 (sshlockout_pf) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 7656 usec to 3871 usec for pid 85797 (sh) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 399904 usec to 202192 usec for pid 86015 (sh) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 5458 usec to 2759 usec for pid 86015 (sh) Sep 9 17:28:09 kernel: calcru: runtime went backwards from 1286 usec to 650 usec for pid 88638 (sleep)Hyper-V in Server 2012
2.2-ALPHA (amd64) built on Tue Sep 09 10:49:11 CDT 2014 FreeBSD 10.1-PRERELEASE
These errors happened on a clean install, though I did restore my old config. -
Complete guess, but if you look at the time differences, you'll see them changing about 50%. Sounds like NTP syncing system time.
-
Why is this being logged though? Shouldn't the NTP sync be automatic and silent? It's not a big deal but these messages fill up my screen sometimes. Do you get these messages on your pfSense?
-
@piz0t:
Do you get these messages on your pfSense?
Yes, but i can handle it.
-
Ok, if it's normal and not a bug, I'll mark this thread as solved. Thanks for the answers.