I just experienced a 2 hour power failure, which was long enough for my APC UPSs to power down. However, I have one UPS on my Linux computer and the other on my pfSense firewall. I noticed that the firewall one, which runs on FreeBSD, provided more info that the one on Linux. Any idea why that may be? Both UPSs are the same model and age. Linux - This is the entire apcupsd.events file 2021-04-09 21:06:00 -0400 Power failure. 2021-04-09 21:06:00 -0400 Power is back. UPS running on mains. 2021-04-09 21:06:00 -0400 Power failure. 2021-04-09 21:06:00 -0400 Power is back. UPS running on mains. 2021-04-09 21:06:01 -0400 Power failure. 2021-04-09 21:06:07 -0400 Running on UPS batteries. 2021-04-09 23:00:05 -0400 apcupsd 3.14.14 (31 May 2016) suse startup succeeded pfSense - This is the last several lines of the apcupsd.events file, which goes back to Feb. 22. 2021-04-06 05:56:40 -0400 UPS Self Test switch to battery. 2021-04-06 05:56:49 -0400 UPS Self Test completed: Battery OK 2021-04-09 21:05:59 -0400 Power failure. 2021-04-09 21:06:05 -0400 Running on UPS batteries. 2021-04-09 22:01:59 -0400 Battery charge below low limit. 2021-04-09 22:01:59 -0400 Initiating system shutdown! 2021-04-09 22:01:59 -0400 User logins prohibited 2021-04-09 22:01:59 -0400 apcupsd exiting, signal 15 2021-04-09 22:02:00 -0400 apcupsd shutdown succeeded 2021-04-09 23:00:43 -0400 apcupsd 3.14.14 (31 May 2016) freebsd startup succeeded This one shows not only more info about the shutdown, but also a self test 3 days ago. Why the difference with the Linux system.?
On Fri, 9 Apr 2021, James Knott wrote:
I just experienced a 2 hour power failure, which was long enough for my APC UPSs to power down. However, I have one UPS on my Linux computer and the other on my pfSense firewall. I noticed that the firewall one, which runs on FreeBSD, provided more info that the one on Linux. Any idea why that may be? Both UPSs are the same model and age.
Linux - This is the entire apcupsd.events file
2021-04-09 21:06:00 -0400 Power failure. 2021-04-09 21:06:00 -0400 Power is back. UPS running on mains. 2021-04-09 21:06:00 -0400 Power failure. 2021-04-09 21:06:00 -0400 Power is back. UPS running on mains. 2021-04-09 21:06:01 -0400 Power failure. 2021-04-09 21:06:07 -0400 Running on UPS batteries. 2021-04-09 23:00:05 -0400 apcupsd 3.14.14 (31 May 2016) suse startup succeeded
pfSense - This is the last several lines of the apcupsd.events file, which goes back to Feb. 22.
2021-04-06 05:56:40 -0400 UPS Self Test switch to battery. 2021-04-06 05:56:49 -0400 UPS Self Test completed: Battery OK 2021-04-09 21:05:59 -0400 Power failure. 2021-04-09 21:06:05 -0400 Running on UPS batteries. 2021-04-09 22:01:59 -0400 Battery charge below low limit. 2021-04-09 22:01:59 -0400 Initiating system shutdown! 2021-04-09 22:01:59 -0400 User logins prohibited 2021-04-09 22:01:59 -0400 apcupsd exiting, signal 15 2021-04-09 22:02:00 -0400 apcupsd shutdown succeeded 2021-04-09 23:00:43 -0400 apcupsd 3.14.14 (31 May 2016) freebsd startup succeeded
This one shows not only more info about the shutdown, but also a self test 3 days ago. Why the difference with the Linux system.?
The "low limit" is not detected on the Linux box. Did it crash? Were the two apcupsd configuration files /etc/apcupsd/apcupsd.conf identical? How old are these batteries? Roger
On 2021-04-10 3:02 a.m., Roger Price wrote:
The "low limit" is not detected on the Linux box. Did it crash?
Were the two apcupsd configuration files /etc/apcupsd/apcupsd.conf identical?
How old are these batteries? Both batteries have a date of 2018-07-27. Both systems were up for over an hour. As far as I can tell, both configurations are the same.
On Sat, 10 Apr 2021, James Knott wrote:
On 2021-04-10 3:02 a.m., Roger Price wrote:
The "low limit" is not detected on the Linux box. Did it crash?
What does the system log show as the Linux box shuts down? I would expect to see something like: ... Jan 26 08:00:37 maria systemd[1]: Reached target Shutdown. Jan 26 08:00:38 maria upsdrvctl[1922]: Using subdriver: MGE HID 1.39 Jan 26 08:00:38 maria upsdrvctl[1922]: Network UPS Tools - Generic HID driver 0.41 (2.7.4) Jan 26 08:00:38 maria upsdrvctl[1922]: USB communication driver 0.33 Jan 26 08:00:39 maria upsdrvctl[1922]: Initiating UPS shutdown Jan 26 08:00:39 maria upsdrvctl[1922]: Network UPS Tools - UPS driver controller 2.7.4 Jan 26 08:00:39 maria systemd[1]: Started Initiate delayed UPS shutdown. Jan 26 08:00:39 maria systemd[1]: Reached target Unmount All Filesystems. Jan 26 08:00:39 maria systemd[1]: Reached target Final Step. Jan 26 08:00:39 maria systemd[1]: Starting Power-Off... Jan 26 08:00:39 maria systemd[1]: Shutting down. Jan 26 08:00:39 maria kernel: systemd-shutdow: 30 output lines suppressed due to ratelimiting Jan 26 08:00:39 maria systemd-shutdown[1]: Sending SIGTERM to remaining processes... Jan 26 08:00:39 maria systemd-journald[303]: Journal stopped which shows that this is a controlled systemd shutdown and not a crash. It also shows that a "delayed UPS shutdown" has been sent to the UPS, so that it will turn off it's outlet sockets _after_ the Linux box has shut down, thus ensuring an automatic restart when power returns. Roger
On 2021-04-10 12:08 p.m., Roger Price wrote:
On Sat, 10 Apr 2021, James Knott wrote:
On 2021-04-10 3:02 a.m., Roger Price wrote:
The "low limit" is not detected on the Linux box. Did it crash?
How are you viewing that? I didn't see much in dmesg and I don't see any files that refer to system log. Even doing a google search doesn't turn up much.
On 10/04/2021 18.42, James Knott wrote:
On 2021-04-10 12:08 p.m., Roger Price wrote:
On Sat, 10 Apr 2021, James Knott wrote:
On 2021-04-10 3:02 a.m., Roger Price wrote:
The "low limit" is not detected on the Linux box. Did it crash?
How are you viewing that? I didn't see much in dmesg and I don't see any files that refer to system log. Even doing a google search doesn't turn up much.
It should be in syslog (permanent), not dmesg (volatile). File "/var/log/messages". Otherwise, it would be in the system journal, if configured as permanent. Command "journalctl" -- Cheers / Saludos, Carlos E. R. (from 15.2 x86_64 at Telcontar)
On Sat, 10 Apr 2021 15:24:03 -0400 James Knott <james.knott@jknott.net> wrote:
On 2021-04-10 1:29 p.m., Carlos E. R. wrote:
Command "journalctl"
That shows stuff that happened after 8:05 this morning, which is when I rebooted after a kernel update.
So RTFM and supply the appropriate parameters to look beyond that?
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 On Saturday, 2021-04-10 at 15:24 -0400, James Knott wrote:
On 2021-04-10 1:29 p.m., Carlos E. R. wrote:
Command "journalctl"
That shows stuff that happened after 8:05 this morning, which is when I rebooted after a kernel update.
No. Telcontar:~ # journalctl | head - -- Logs begin at Sun 2020-08-09 14:33:00 CEST, end at Sat 2021-04-10 22:24:12 CEST. -- Aug 09 14:33:00 Telcontar openvpn[31753]: UID set to nobody Aug 09 14:33:00 Telcontar openvpn[31753]: Initialization Sequence Completed I said "if configured as permanent". You don't have it configured at permanent, so you only see the current boot. Create the directory "/var/log/journal/" if you want a permanent journal. You may prefer syslog, though. I use both. - -- Cheers, Carlos E. R. (from openSUSE 15.2 x86_64 at Telcontar) -----BEGIN PGP SIGNATURE----- iHoEARECADoWIQQZEb51mJKK1KpcU/W1MxgcbY1H1QUCYHIKSxwccm9iaW4ubGlz dGFzQHRlbGVmb25pY2EubmV0AAoJELUzGBxtjUfVN50An2qmhhm/OiQpaSN3FwYj kZZU2gDFAKCEqJeDU5ZoPnsxY2ryAXrASdIEsQ== =5aw0 -----END PGP SIGNATURE-----
On 2021-04-10 4:27 p.m., Carlos E. R. wrote:
That shows stuff that happened after 8:05 this morning, which is when I rebooted after a kernel update.
No.
Telcontar:~ # journalctl | head - -- Logs begin at Sun 2020-08-09 14:33:00 CEST, end at Sat 2021-04-10 22:24:12 CEST. -- Aug 09 14:33:00 Telcontar openvpn[31753]: UID set to nobody Aug 09 14:33:00 Telcontar openvpn[31753]: Initialization Sequence Completed
# journalctl|head -- Logs begin at Sat 2021-04-10 08:05:02 EDT, end at Sat 2021-04-10 16:29:09 EDT. -- Apr 10 08:05:02 linux kernel: microcode: microcode updated early to revision 0x21, date = 2019-02-13 Apr 10 08:05:02 linux kernel: Linux version 5.3.18-lp152.69-default (geeko@buildhost) (gcc version 7.5.0 (SUSE Linux)) #1 SMP Tue Apr 6 11:41:13 UTC 2021 (d532e33) Apr 10 08:05:02 linux kernel: Command line: BOOT_IMAGE=/vmlinuz-5.3.18-lp152.69-default root=UUID=6eea2df3-3ff3-4d25-b73c-fa782d63a217 splash=silent resume=/dev/disk/by-uuid/6af126cc-6d55-478e-b2d4-249fcc92277c mitigations=auto quiet Apr 10 08:05:02 linux kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' Apr 10 08:05:02 linux kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' Apr 10 08:05:02 linux kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' Apr 10 08:05:02 linux kernel: x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 Apr 10 08:05:02 linux kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. Apr 10 08:05:02 linux kernel: BIOS-provided physical RAM map: That sure looks like it started after reboot to me.
On 4/9/21 10:15 PM, James Knott wrote:
This one shows not only more info about the shutdown, but also a self test 3 days ago. Why the difference with the Linux system.?
Likely due to where apcupsd is started in the boot sequence and whether the journal is active when the self-test is performed. For my Linux boxes, the self-test occurs before the journal starts. I can see a firewall with it's near instant-on, having logging enabled before the self-test occurs. -- David C. Rankin, J.D.,P.E.
On 2021-04-12 1:43 p.m., David C. Rankin wrote:
This one shows not only more info about the shutdown, but also a self test 3 days ago. Why the difference with the Linux system.? Likely due to where apcupsd is started in the boot sequence and whether the journal is active when the self-test is performed. For my Linux boxes, the self-test occurs before the journal starts. I can see a firewall with it's near instant-on, having logging enabled before the self-test occurs.
That might be it. My firewall computer is a Qotom mini PC, with i5 CPU, 4 GB of memory, 64 GB SSD and 4 Ethernet ports. It's a lot faster than the HP compact computer it replaced. With the HP, on my 500/20 Internet connection, I'd typically see upper 500s with speedtest. Here's my best result with the Qotom: https://www.speedtest.net/result/11030619542 I've even seen over 800 when using the command line speedtest running on the firewall.
On 12/04/2021 19.43, David C. Rankin wrote:
On 4/9/21 10:15 PM, James Knott wrote:
This one shows not only more info about the shutdown, but also a self test 3 days ago. Why the difference with the Linux system.?
Likely due to where apcupsd is started in the boot sequence and whether the journal is active when the self-test is performed.
No, this is not possible, the journal by definition has information on the start of every service. For instance, when the journal starts, it gets information dumped by the kernel boot from "way before". If the journal doesn't have information on some service, that's a bug. -- Cheers / Saludos, Carlos E. R. (from 15.2 x86_64 at Telcontar)
participants (5)
-
Carlos E. R. -
Dave Howorth -
David C. Rankin -
James Knott -
Roger Price