SG-1100: unexpexcted reboots and vm_fault in logs - how to diagnose?
-
Hi,
I have an SG 1100 which suddenly does unexpected reboots. When I look at the system logs I see lots of
vm_fault: pager read error, pid 12899 (rrdtool)What I have done so far:
- zfs scrub - no errors
- chec emmc state per https://docs.netgate.com/pfsense/en/latest/troubleshooting/disk-lifetime.html#emmc - everything less than 10/20 % use
What else can I check to see if I need a replacement?
-
Do you see a crash report after it reboots?
-
@stephenw10 where would I see it?
When I log in after a reboot I don't see any special notification. I just had a second look at the system logs and the messages around the last reboot are gone. The logs are now filled with "pager read error" entries. Every ~30 entries there is one like this
"pid 56861 (rrdtool), jid 0, uid 0: exited on signal 10 (core dumped)" -
'Page read error' seems like a memory issue.
What is the actual error shown?
-
@stephenw10 That's all I see. Should I look somewhere else to get details?
-
Do you have SWAP enabled? RAM disks?
Is it exhausting the RAM? Disk full?
-
@stephenw10 Thank you for your inputs, but can you advise on where to check this?
All I did was set it up a few weeks ago with the latest image (had to install via console) and ZFS enabled. Then I enabled pfblockerng (added some feeds) and that's it.
I am happy to check everything, but need to know where :) (Sorry for the pfsense newbie questions)
From the dashboard, RAM + disks do not look full:
-
Yup that looks fine. Also no SWAP. That does mean no crash reports though.
How often is this happening? One option here would be to connect to the console and leave a client there logging the output when it crashes.
-
@stephenw10 difficult to say - i only notice it if it reboots while I am working. It can be between 1-2 a day but it could also be that it runs fine for a few days (right now it's been up for 1 day 5 hours).
Leaving a client on is not as easy, since I mainly have laptopts which are in use (my own + my wifes work laptop). Which logs would I look at?
Is there a way to retain the logs for more time?If possible I could attach a USB stick and set some verbose logging to that destination?
An additional note: while looking at the log files, one file stuck out where the last time modified was around when the last reboot happened. These are the contents of gateways.log:
Sep 21 16:10:51 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:51 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:52 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:52 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:53 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:53 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:54 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:54 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:55 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:55 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:56 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:56 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:10:57 pfSense dpinger[76975]: WAN_DHCP 100.82.0.1: sendto error: 65 Sep 21 16:11:15 pfSense dpinger[76975]: exiting on signal 15 Sep 21 16:11:15 pfSense dpinger[81909]: send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% alarm_hold 10000ms dest_addr 100.82.0.1 bind_addr 100.82.196.79 identifier "WAN_DHCP " -
That just looks like the WAN went down. It shouldn't have caused a crash.
The logging does not capture kernel panic / crash because at that point logging stops. So it doesn't matter how verbose that is set.
If there is SWAP present the device will save the crash report there before rebooting.
So if you cannot leave a device hooked to the console to capture the crash you may be able to add a SWAP partition on a USB drive.
-
@stephenw10 could you detail the steps for the options above?
What would I need to do for console logging? Just connect a client via USB and open a terminal connection or should I do anything specific?
For adding a swap partition on a USB drive I couldn't find any instructions, so unless you can help here I'll try to get hold of an old laptop to connect to the console.
-
Yes, potentially just connect to the console and leave the window open. If you're using putty, for example, you can enable logging and it will store everything in a file. Otherwise you'd have to scroll back through after the crash to see the panic output. Other terminal applications may also log output in different ways.
There are a few variables required to add swap on USB. Some instructions can be found here: https://forum.netgate.com/post/1127502
You don't need to set/etc/pfSense-ddb.confjust to get the normal crash dump.Steve
-
@stephenw10 I had a thought: before going through the hassle of doing what you suggested, I googled again and this time I stumbled on an old post. (see mailing list archive)
So, I did what it said, rebooted and I don't have the errors anymore in the logs (at least not in the last 5-10 minutes ;-)). I will monitor if the reboots still occur.
For the time being, if anybody stumbles on this:
Symptoms:
- system logs filled with LOTS of (some 20-30 entries per minute)
Sep 28 09:29:19 kernel vm_fault: pager read error, pid 44821 (rrdtool) Sep 28 09:29:19 kernel vm_fault: pager read error, pid 44821 (rrdtool) Sep 28 09:29:19 kernel vm_fault: pager read error, pid 44821 (rrdtool) Sep 28 09:29:19 kernel vm_fault: pager read error, pid 44821 (rrdtool) Sep 28 09:29:19 kernel vm_fault: pager read error, pid 44821 (rrdtool) Sep 28 09:29:19 kernel pid 44821 (rrdtool), jid 0, uid 0: exited on signal 10 (core dumped)- irregular reboots (between 2-3 times a day and every few days)
What I did:
rm -rf /var/db/rrd/*- go to the UI in interfaces -> LAN and save + apply
- reboot
-
Hmm, interesting. Let us know how it goes.
I could see bad rrd data files causing the rrdtool core dump but that shouldn't cause the whole firewall to crash. Normally.
-
@stephenw10 I had a reboot this night - so it seems I have to go the console way...
One thing that happened this time is that it was close to when pfblockerng updates its list. Since the other reboots happened any time during day I don't think it's connected.What I don't really understand though is that pfblockerNG seemed to continue updating during reboot.
pfBlockerNG logs (cron start was at 00:15:00 and update took about 2 minutes - so exactly during reboot):
System logs
-
Hmm, odd. Though I'm not sure 2 seconds could confirm that.
Also note the pfBlocker logs are GMT not BST.
-
@stephenw10 could you explain the timezone remark?
I see the file timestamps are marked as GMT. For the times I highlighted I expeted them to be in the same timezone as the system log entries. Is that not the case?If not is there a way to set the timezone to use somewhere? (preferably for all logs, but either for the system logs or for pfblockerNG would already help)
In my case I configured pfBlockerNG to run a daily update at 00:15:00 (so that time matches my local timezone). If I assume that the system logs also use my local time zone (which seems to be the case), those entries would indeed be in the same timeframe.
-
Yes, I expect them to be the same but since we are currently in summer time it seemed suspect. Especially as my own logs are in local time, which is BST for me, but that is not included in the pfblocker log.
What version are you using?
-
@stephenw10 I just learned that I need to update pfblockerNG manually. I updated it to the latest devel version (3.2.0_17)
-
@stephenw10 I managed to have a device attached to the USB console while it crashed. Could you give me a hint on where the dump starts and where it ends?
before the boot logs I see a lot of these:
Tracing command dhclient pid 50093 tid 100224 td 0xffff00009cab5640 sched_switch() at sched_switch+0x890 mi_switch() at mi_switch+0xf8 sleepq_catch_signals() at sleepq_catch_signals+0x424 sleepq_wait_sig() at sleepq_wait_sig+0xc _cv_wait_sig() at _cv_wait_sig+0x10c seltdwait() at seltdwait+0x110 kern_select() at kern_select+0x81c sys_select() at sys_select+0x60 do_el0_sync() at do_el0_sync+0x634 handle_el0_sync() at handle_el0_sync+0x48 --- exception, esr 0x56000000 ``
