PFSense 2.4.4 not responding at console and web interface CRITICAL BUG! HELP!

john_wick

Gate system logs

Mar 3 09:46:55	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 5 23:05:35	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 5 23:05:37	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 8 20:42:49	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 8 20:42:50	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 8 20:42:50	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 8 20:42:51	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 8 20:42:51	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 8 20:42:52	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 8 20:42:52	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 8 20:42:53	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 8 20:42:53	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 8 20:42:54	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 8 20:42:56	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 10 01:23:05	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 10 01:23:09	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 11 09:18:11	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 11 09:18:13	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 13 16:09:48	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 13 16:09:50	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 16 08:55:05	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 16 08:55:07	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 16 11:54:48	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 16 11:54:50	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 16 17:49:32	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 16 17:49:34	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 16 16:58:31	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 16 16:58:35	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 18 14:08:07	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:08	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:09	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:09	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:10	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:10	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:11	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:11	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:12	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:12	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:13	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:13	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 18 14:08:16	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "
Mar 21 21:05:11	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 21 21:05:12	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 21 21:05:12	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 21 21:05:13	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 21 21:05:13	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 21 21:05:14	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 21 21:05:14	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 21 21:05:15	dpinger		WAN_DHCP 176.36.0.1: sendto error: 65
Mar 21 21:05:17	dpinger		send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 176.36.0.1 bind_addr 176.37.xxx.xxx identifier "WAN_DHCP "

stephenw10

You have titled this 2.4.4 but you're asking about the 2.3 branch, which is it?

Steve

stephenw10

And in another thread you're asking about 2.4.3...

john_wick

Hi Stephen I have this errors on both vesions in KVM (Proxmox) hypervisor(
updated version recently). I tryed disable NTP severs change NTP pools reinstall PFsense, cpu units change, Change timecounters without result

In virtualized OpNsense have similar kernel panic with filtellog flood but connection fall down (in PF works DHCP,NAT, etc.

Anytime when I needed acces to cli or web UI I have to suspend and resume VM. I think is temporary solution add to cronjob console comad №11(restart web configurator) with 30-60sec interval.
If this does not work to me IPfire firewall my reserve plan

Similar situations
https://forum.netgate.com/topic/130467/solved-pfsense-2-4-3-halts-with-calcru-messages-in-console/5

https://forum.netgate.com/topic/104013/pfsense-not-responding-at-console/7

stephenw10

So which pfSense version are you testing?

john_wick

Version of my test instalation 2.4.4-RELEASE-p2 (amd64)
Maybe need some logs or output?
I think is problem with webconfigurator how to add correct cron job comand like: 1 * * * * root etc/rc.restart_webgui ? This can work?

stephenw10

Ok, so how are you seeing that logs if you have no access to the GUI or console? Does it not fail immediately?

What are the results of: sysctl kern.timecounter

Steve

john_wick

[2.4.4-RELEASE][root@pfSense.localdomain]/root: sysctl kern.timecounter
kern.timecounter.tsc_shift: 1
kern.timecounter.smp_tsc_adjust: 0
kern.timecounter.smp_tsc: 0
kern.timecounter.invariant_tsc: 0
kern.timecounter.fast_gettime: 1
kern.timecounter.tick: 1
kern.timecounter.choice: i8254(0) ACPI-fast(900) HPET(950) TSC-low(800) dummy(-1000000)
kern.timecounter.hardware: HPET
kern.timecounter.alloweddeviation: 5
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.counter: 7474
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.counter: 12623953
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.HPET.frequency: 100000000
kern.timecounter.tc.HPET.counter: 3428655973
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.TSC-low.quality: 800
kern.timecounter.tc.TSC-low.frequency: 1199709078
kern.timecounter.tc.TSC-low.counter: 4238456201
kern.timecounter.tc.TSC-low.mask: 4294967295

stephenw10

You might try switching to one of the other timecounters:
sysctl kern.timecounter.hardware=ACPI-fast

You can add that in System Tunables if it fixes it.

Steve

john_wick

@stephenw10 When i suspend and resume Pfsense VM in Proxmox cli and web gui unfrozen + (have some kernel messages calcru) but it works and trafig hase go even webui/cli have not response. I conect fro my nat on 192.168.1.1
I have low trafic and load resources up to 30% max
Maybe need to try set maximum performance in bios? Irony in the situation that linux work more stable over bsd system in my test lab :(

stephenw10

You mean shutdown and restart or actually suspend?

john_wick

@stephenw10 Without reboot only suspend like pause/resume

stephenw10

Hmm, not sure I've ever tried that. Does it only show that error when you resume it?

john_wick

@stephenw10 said in PFSense 2.4.4 not responding at console and web interface CRITICAL BUG! HELP!:

You might try switching to one of the other timecounters:
sysctl kern.timecounter=ACPI-fast

You can add that in System Tunables if it fixes it.

Steve

alt timecounter

stephenw10

Sorry I missed a bit there, the sysctl should be kern.timecounter.hardware

Did you try it at the command line first?

Steve

john_wick

@stephenw10
Mostly yes. According to my observations, sometimes the calcru error enters the log not immediately, but at intervals after a pause. Basically, the console simply stops responding or responding via ssh and the web UI stops responding sometimes with a 502 bad gateway. Now I have installed sysctl kern.timecounter = ACPI-fast will reboot and look at the reaction. If I fail, I will try to improve performance and frequency.

john_wick

@stephenw10 said in PFSense 2.4.4 not responding at console and web interface CRITICAL BUG! HELP!:

Sorry I missed a bit there, the sysctl should be kern.timecounter.hardware

Did you try it at the command line first?

Steve

Like this alt text Hase a diference with cli or with UI config edit?

stephenw10

That's correct. It will apply via the GUI like that but it's then permanent. If you test it from the CLI first and it does something unexpected you can just reboot.

Steve

john_wick

Hi Stepen yesterday error is gone and server work stable access to cli and web UI was anytime when was small trafic but after night when trafic was zero error come back again. Need more time to watch on the actions and need to tweak to max performance or maybe I can add some cron jobs to prevent falling asleep webconfigurator or this is more fundamental timecounter problems?

Mar 25 15:08:27	kernel		calcru: runtime went backwards from 685818 usec to 353871 usec for pid 24 (syncer)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 685818 usec to 353871 usec for pid 24 (syncer)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 17 usec to 8 usec for pid 5 (sctp_iterator)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 18 usec to 9 usec for pid 5 (sctp_iterator)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 182 usec to 93 usec for pid 15 (usb)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 164420 usec to 83927 usec for pid 4 (cam)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 5 usec to 2 usec for pid 2 (crypto)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 19805 usec to 10109 usec for pid 14 (geom)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 21765 usec to 11109 usec for pid 14 (geom)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 1094 usec to 558 usec for pid 14 (geom)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 7510 usec to 3833 usec for pid 14 (geom)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 10 usec to 5 usec for pid 13 (ng_queue)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 15 usec to 8 usec for pid 13 (ng_queue)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 33 usec to 17 usec for pid 12 (intr)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 928 usec to 474 usec for pid 12 (intr)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 949204 usec to 490190 usec for pid 12 (intr)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 1790 usec to 1195 usec for pid 12 (intr)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 10823 usec to 5572 usec for pid 1 (init)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 20126323 usec to 10274286 usec for pid 1 (init)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 10823 usec to 5572 usec for pid 1 (init)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 10 usec to 5 usec for pid 10 (audit)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 42471156539 usec to 21679250280 usec for pid 0 (kernel)

Mar 25 15:08:27	kernel		calcru: runtime went backwards from 7 usec to 3 usec for pid 0 (kernel)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 13 usec to 6 usec for pid 0 (kernel)
Mar 25 15:08:27	kernel		calcru: runtime went backwards from 9 usec to 4 usec for pid 0 (kernel)

stephenw10

kern.timecounter.hardware is still set to ACPI-fast?