proto
Patron
- Joined
- Sep 28, 2015
- Messages
- 269
This week I had two power failures due to storms and my FreeNAS server suffered an unscheduled system reboot.
Actually my FreeNAS server is attached to a pfSense box via NUT and should get notification in case of power failures.
UPS model is a Riello VSD 3000, connected via usb-serial.
I need to find a better solution, because it seems unreliable in my current setup.
Should I connect my main UPS directly to me FreeNAS server or do you have any suggestions?
Meanwhile, this is what happened:
I got this email notification only *after* a system power on and working network connection:
I checked in /var/log/maillog and found that my ups went ONBATT @ 01:37:33, but email failed:
I guess pfSense has been powered off and could not offer any services and networking... I could only check that around 01:40:00 my pfSense box stopped any activity as it had been shut down.
In /var/log/messages I can see UPS is ONLINE, so NUT didn't initiate the shutdown:
But /var/log/ups.log shows:
But I dont't understand why /var/log/maillog is reporting this line:
So what I really don't realize is what time exactly FreeNAS has been shut down! Is not possible that an UPS with 5% only can sustain all that workload even if it's not "really" working at that time of the day: it's just powered on. One log (ups.log) is telling me, hey I'm dead and I have only 5%, maillog is saying I'm still alive two hours later... 05:15 - 02:52 is a big delta.
When I say all that workload is because, there are switches and other stuff connected to the UPS.
Time for middlewared.log:
Error is networking here: socket.gaierror: [Errno 8] hostname nor servname provided, or not known
pfSense is down, so no net!
But middlewared.log is telling more, but I don't know what happened here:
So probably FreeNAS has been restarted... but I don't see evidence and last is saying this:
No shutdown in last messages... I'm stuck, or maybe I'm a bit tired and I don't see what happened.
Actually my FreeNAS server is attached to a pfSense box via NUT and should get notification in case of power failures.
UPS model is a Riello VSD 3000, connected via usb-serial.
I need to find a better solution, because it seems unreliable in my current setup.
Should I connect my main UPS directly to me FreeNAS server or do you have any suggestions?
Meanwhile, this is what happened:
I got this email notification only *after* a system power on and working network connection:
Code:
From: me@DOMAIN.com To: me@DOMAIN.com Date: Thu, 23 May 2019 05:05:31 -0000 Subject: bestia.INTERNAL.prv: Unscheduled system reboot bestia.INTERNAL.prv had an unscheduled system reboot. The operating system successfully came back online at Thu May 23 05:05:31 2019.
I checked in /var/log/maillog and found that my ups went ONBATT @ 01:37:33, but email failed:
Code:
May 23 01:37:33 bestia /find_alias_for_smtplib.py[33334]: sending mail to me@DOMAIN.com To: me@DOMAIN.com Subject: UPS report generated by bestia.INTERNAL.prv ONBATT - ups@10.10.10.1:3493 May 22 23:38:07 bestia /middlewared[310]: Failed to send email to me@DOMAIN.com: [Errno 8] hostname nor servname provided, or not known
I guess pfSense has been powered off and could not offer any services and networking... I could only check that around 01:40:00 my pfSense box stopped any activity as it had been shut down.
In /var/log/messages I can see UPS is ONLINE, so NUT didn't initiate the shutdown:
Code:
May 23 00:00:00 bestia newsyslog[27981]: logfile turned over due to size>200K May 23 00:00:00 bestia syslog-ng[2911]: Configuration reload request received, reloading configuration; May 23 00:00:00 bestia syslog-ng[2911]: Configuration reload finished; May 23 01:37:32 bestia upsmon[3551]: UPS ups@10.10.10.1:3493 on battery May 23 01:38:02 bestia upssched-cmd: Shutdown not initiated as ups.status indicates ups@10.10.10.1:3493 is ONLINE (OL) May 23 07:05:51 bestia syslog-ng[2917]: syslog-ng starting up; version='3.20.1' May 23 07:05:51 bestia Copyright (c) 1992-2018 The FreeBSD Project.
But /var/log/ups.log shows:
Code:
20190523 012720 100 229 10 [OL] 45 50.00 20190523 013220 100 228 10 [OL] 45 50.00 20190523 013720 100 232 10 [OL] 45 50.00 # POWER is ON 20190523 014221 76 0 14 [OB] 32 0.00 # POWER is DOWN 20190523 014720 73 0 12 [OB] 31 0.00 [...] 20190523 023720 14 0 13 [OB] 31 0.00 20190523 024220 13 0 11 [OB] 31 0.00 20190523 024720 8 0 12 [OB] 31 0.00 20190523 025220 5 0 12 [OB] 31 0.00 # @ 02:52 POWER charge is 5% 20190523 070552 22 221 10 [OL CHRG] 31 50.00 # manual power ON
But I dont't understand why /var/log/maillog is reporting this line:
Code:
May 23 05:15:38 bestia /middlewared[310]: sending mail to me@DOMAIN.com
So what I really don't realize is what time exactly FreeNAS has been shut down! Is not possible that an UPS with 5% only can sustain all that workload even if it's not "really" working at that time of the day: it's just powered on. One log (ups.log) is telling me, hey I'm dead and I have only 5%, maillog is saying I'm still alive two hours later... 05:15 - 02:52 is a big delta.
When I say all that workload is because, there are switches and other stuff connected to the UPS.
Time for middlewared.log:
Code:
[2019/05/22 23:47:32] (DEBUG) MailService.send_mail_queue():356 - Sending message from queue failed [2019/05/22 23:57:32] (DEBUG) MailService.send_mail_queue():356 - Sending message from queue failed [2019/05/23 00:07:33] (DEBUG) MailService.send_mail_queue():356 - Sending message from queue failed
Error is networking here: socket.gaierror: [Errno 8] hostname nor servname provided, or not known
pfSense is down, so no net!
But middlewared.log is telling more, but I don't know what happened here:
Code:
[2019/05/23 05:05:27] (DEBUG) raven.base.Client.set_dsn():265 - Configuring Raven for host: https://sentry.ixsystems.com [2019/05/23 05:05:31] (DEBUG) middlewared.__plugins_load():809 - All plugins loaded
So probably FreeNAS has been restarted... but I don't see evidence and last is saying this:
Code:
root@bestia[~]# last | head -30 root pts/0 10.10.20.13 Thu May 23 12:01 still logged in root pts/0 10.10.20.13 Thu May 23 11:41 - 11:45 (00:03) root pts/0 10.10.20.13 Thu May 23 08:52 - 09:08 (00:15) root pts/0 10.10.20.13 Thu May 23 07:34 - 07:46 (00:11) root pts/1 Thu May 23 07:10 - 07:11 (00:00) root pts/0 10.10.20.13 Thu May 23 07:06 - 07:20 (00:14) boot time Thu May 23 07:05 ### HERE is when I pressed the button! ### root pts/2 10.10.20.13 Wed May 22 21:03 - 21:17 (00:13) root pts/0 10.10.20.13 Wed May 22 20:59 - 21:17 (00:18) root pts/3 Wed May 22 17:55 - 17:55 (00:00)
No shutdown in last messages... I'm stuck, or maybe I'm a bit tired and I don't see what happened.