Georgi D. Sotirov
2020-Jan-11 11:18 UTC
[Nut-upsuser] System with MGE UPS shuts down too early
Hello,
I'm experiencing a strange early shutdown behavior with the following
system:
* */OS/*: Slackware Linux 14.2 x86_64
* */NUT/*: 2.7.4 (from my own package
<https://sotirov-bg.net/slackpack/pack.cgi?id=4083>)
* */UPS/*: MGE Ellipse PRO 1600
<powerquality.eaton.com/Products-services/Backup-Power-UPS/Ellipse-PRO.aspx>
(bought in September 2017)
*/Problem description/*: An hour ago there was a power outage for about
3-4 minutes. However, the system was forcefully shut down just after a
minute (!) and I'm not sure I understand why. This is what I found into
the logs:
* /var/log/messages (only relevant):
Jan 11 11:49:15 sotirov-bg upsmon[2677]: UPS mgeups at localhost on battery
Jan 11 11:49:15 sotirov-bg upssched[29746]: Executing command:
ups-on-battery
Jan 11 11:49:15 sotirov-bg upssched-cmd: Unrecognized command:
ups-on-battery
Jan 11 11:50:20 sotirov-bg upsmon[2677]: UPS mgeups at localhost battery is low
Jan 11 11:50:20 sotirov-bg upsd[2672]: Client monuser at 127.0.0.1 set FSD
on UPS [mgeups]
Jan 11 11:50:20 sotirov-bg upsmon[2677]: Auto logout and shutdown proceeding
Jan 11 11:50:20 sotirov-bg upssched[30461]: Executing command: ups-low-batt
Jan 11 11:50:20 sotirov-bg upssched-cmd: Unrecognized command: ups-low-batt
Jan 11 11:50:20 sotirov-bg upssched[30466]: Executing command: ups-shutdown
Jan 11 11:50:20 sotirov-bg upssched-cmd: Unrecognized command: ups-shutdown
Jan 11 11:50:25 sotirov-bg shutdown[30471]: shutting down for system halt
Jan 11 11:50:25 sotirov-bg init: Switching to runlevel: 0
* /var/log/ups (snippet of consecutive messages):
20200111 114901 100 221.0 17 [OL] NA 50.0
20200111 114906 100 221.0 17 [OL] NA 50.0
20200111 114911 100 221.0 17 [OL] NA 50.0
20200111 114916 99 0.0 19 [OB] NA 0.0
20200111 114921 99 0.0 19 [OB] NA 0.0
20200111 114926 99 0.0 19 [OB] NA 0.0
20200111 114931 99 0.0 19 [OB] NA 0.0
20200111 114936 99 0.0 19 [OB] NA 0.0
20200111 114941 99 0.0 19 [OB] NA 0.0
20200111 114946 98 0.0 16 [OB] NA 0.0
20200111 114951 98 0.0 16 [OB] NA 0.0
20200111 114956 98 0.0 16 [OB] NA 0.0
20200111 115001 98 0.0 16 [OB] NA 0.0
20200111 115006 98 0.0 16 [OB] NA 0.0
20200111 115011 98 0.0 16 [OB] NA 0.0
20200111 115016 98 0.0 16 [OB] NA 0.0
20200111 115021 96 0.0 18 [FSD ALARM OB LB] NA 0.0
20200111 115026 96 0.0 18 [FSD ALARM OB LB] NA 0.0
20200111 115031 96 0.0 18 [FSD ALARM OB LB] NA 0.0
20200111 115036 96 0.0 18 [FSD ALARM OB LB] NA 0.0
20200111 115041 96 0.0 18 [FSD ALARM OB LB] NA 0.0
20200111 115044 96 0.0 18 [FSD ALARM OB LB] NA 0.0
20200111 120209 NA NA NA [WAIT] NA NA
20200111 120214 84 217.0 16 [OL] NA 50.0
20200111 120219 84 217.0 16 [OL] NA 50.0
20200111 120224 84 217.0 16 [OL] NA 50.0
What bugs me is that for just over a minute on battery power the status
changes to FSD ALARM OB LB (see in red above), while at this moment the
battery charge is 96 % (!?). After the power was restored the system
didn't come up, so I had to power it up manually. Checking the battery
charge afterwards it was still 85 %, so I'm really not sure why NUT
shutdown the system so early. I have tested the shutdown sequence in
September 2017 after I installed the UPS by manually removing the online
power and the system was shutdown properly after about 30 minutes. In
several previous occasions I didn't notice such problem and the system
was shutdown after the battery reached the critical charge level of 20%
or managed to discharge the battery until online power restored.
Any suggestions what could be the problem? What does this "ALARM" in
status mean? I checked older ups monitor logs and I did not find such
status.
Best regards,
--
Georgi
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://alioth-lists.debian.net/pipermail/nut-upsuser/attachments/20200111/e2e00409/attachment.html>
Manuel Wolfshant
2020-Jan-11 12:24 UTC
[Nut-upsuser] System with MGE UPS shuts down too early
On January 11, 2020 1:18:27 PM GMT+02:00, "Georgi D. Sotirov" <gdsotirov at gmail.com> wrote:>Hello, > >I'm experiencing a strange early shutdown behavior with the following >system: > > * */OS/*: Slackware Linux 14.2 x86_64 > * */NUT/*: 2.7.4 (from my own package > <https://sotirov-bg.net/slackpack/pack.cgi?id=4083>) > * */UPS/*: MGE Ellipse PRO 1600 ><powerquality.eaton.com/Products-services/Backup-Power-UPS/Ellipse-PRO.aspx> > (bought in September 2017) > >*/Problem description/*: An hour ago there was a power outage for about > >3-4 minutes. However, the system was forcefully shut down just after a >minute (!) and I'm not sure I understand why. This is what I found into > >the logs: > > * /var/log/messages (only relevant): > >Jan 11 11:49:15 sotirov-bg upsmon[2677]: UPS mgeups at localhost on >battery >Jan 11 11:49:15 sotirov-bg upssched[29746]: Executing command: >ups-on-battery >Jan 11 11:49:15 sotirov-bg upssched-cmd: Unrecognized command: >ups-on-battery >Jan 11 11:50:20 sotirov-bg upsmon[2677]: UPS mgeups at localhost battery >is low >Jan 11 11:50:20 sotirov-bg upsd[2672]: Client monuser at 127.0.0.1 set FSD > >on UPS [mgeups] >Jan 11 11:50:20 sotirov-bg upsmon[2677]: Auto logout and shutdown >proceeding >Jan 11 11:50:20 sotirov-bg upssched[30461]: Executing command: >ups-low-batt >Jan 11 11:50:20 sotirov-bg upssched-cmd: Unrecognized command: >ups-low-batt >Jan 11 11:50:20 sotirov-bg upssched[30466]: Executing command: >ups-shutdown >Jan 11 11:50:20 sotirov-bg upssched-cmd: Unrecognized command: >ups-shutdown >Jan 11 11:50:25 sotirov-bg shutdown[30471]: shutting down for system >halt >Jan 11 11:50:25 sotirov-bg init: Switching to runlevel: 0 > > * /var/log/ups (snippet of consecutive messages): > >20200111 114901 100 221.0 17 [OL] NA 50.0 >20200111 114906 100 221.0 17 [OL] NA 50.0 >20200111 114911 100 221.0 17 [OL] NA 50.0 >20200111 114916 99 0.0 19 [OB] NA 0.0 >20200111 114921 99 0.0 19 [OB] NA 0.0 >20200111 114926 99 0.0 19 [OB] NA 0.0 >20200111 114931 99 0.0 19 [OB] NA 0.0 >20200111 114936 99 0.0 19 [OB] NA 0.0 >20200111 114941 99 0.0 19 [OB] NA 0.0 >20200111 114946 98 0.0 16 [OB] NA 0.0 >20200111 114951 98 0.0 16 [OB] NA 0.0 >20200111 114956 98 0.0 16 [OB] NA 0.0 >20200111 115001 98 0.0 16 [OB] NA 0.0 >20200111 115006 98 0.0 16 [OB] NA 0.0 >20200111 115011 98 0.0 16 [OB] NA 0.0 >20200111 115016 98 0.0 16 [OB] NA 0.0 >20200111 115021 96 0.0 18 [FSD ALARM OB LB] NA 0.0 >20200111 115026 96 0.0 18 [FSD ALARM OB LB] NA 0.0 >20200111 115031 96 0.0 18 [FSD ALARM OB LB] NA 0.0 >20200111 115036 96 0.0 18 [FSD ALARM OB LB] NA 0.0 >20200111 115041 96 0.0 18 [FSD ALARM OB LB] NA 0.0 >20200111 115044 96 0.0 18 [FSD ALARM OB LB] NA 0.0 >20200111 120209 NA NA NA [WAIT] NA NA >20200111 120214 84 217.0 16 [OL] NA 50.0 >20200111 120219 84 217.0 16 [OL] NA 50.0 >20200111 120224 84 217.0 16 [OL] NA 50.0 > >What bugs me is that for just over a minute on battery power the status > >changes to FSD ALARM OB LB (see in red above), while at this moment the > >battery charge is 96 % (!?). After the power was restored the system >didn't come up, so I had to power it up manually. Checking the battery >charge afterwards it was still 85 %, so I'm really not sure why NUT >shutdown the system so early. I have tested the shutdown sequence in >September 2017 after I installed the UPS by manually removing the >online >power and the system was shutdown properly after about 30 minutes. In >several previous occasions I didn't notice such problem and the system >was shutdown after the battery reached the critical charge level of 20% or managed to discharge the battery until online power restored. > >Any suggestions what could be the problem? What does this "ALARM" in >status mean? I checked older ups monitor logs and I did not find such >status. > >"Jan 11 11:50:20 sotirov-bg upsmon[2677]: UPS mgeups at localhost battery is low" indicates that the UPS thought that battery was close to depleted and decided to shutdown. I suggest to fully retest your battery ( doing a full charge/discharge cycle with a dummy load ), I suspect it is not any more as good as you believe it to be. wolfy
Georgi D. Sotirov
2020-Jan-11 13:02 UTC
[Nut-upsuser] System with MGE UPS shuts down too early
OK. I'll try it, but it really puzzles me how the battery could have gone bad for just 15 months. The online power is pretty stable, so the battery hasn't gone through many charge/discharge cycles... Regards, -- Georgi On 11.1.2020 at 14:24, Manuel Wolfshant wrote:> > indicates that the UPS thought that battery was close to depleted and decided to shutdown. I suggest to fully retest your battery ( doing a full charge/discharge cycle with a dummy load ), I suspect it is not any more as good as you believe it to be. > > > wolfy
On Sat, 11 Jan 2020, Georgi D. Sotirov wrote:> Jan 11 11:49:15 sotirov-bg upsmon[2677]: UPS mgeups at localhost on battery > Jan 11 11:49:15 sotirov-bg upssched[29746]: Executing command: ups-on-battery > Jan 11 11:49:15 sotirov-bg upssched-cmd: Unrecognized command: ups-on-batteryThese lines say that you have something like AT ONBATT mgeups at localhost EXECUTE ups-on-battery declared in file upssched.conf, but script upssched-cmd does not have a case statement option or something similar to catch such a call to upssched-cmd. Roger
Manuel Wolfshant
2020-Jan-11 15:52 UTC
[Nut-upsuser] System with MGE UPS shuts down too early
On January 11, 2020 3:42:15 PM GMT+02:00, Roger Price <roger at rogerprice.org> wrote:>On Sat, 11 Jan 2020, Georgi D. Sotirov wrote: > >> Jan 11 11:49:15 sotirov-bg upsmon[2677]: UPS mgeups at localhost on >battery >> Jan 11 11:49:15 sotirov-bg upssched[29746]: Executing command: >ups-on-battery >> Jan 11 11:49:15 sotirov-bg upssched-cmd: Unrecognized command: >ups-on-battery > >These lines say that you have something like > > AT ONBATT mgeups at localhost EXECUTE ups-on-battery > >declared in file upssched.conf, but script upssched-cmd does not have a >case >statement option or something similar to catch such a call to >upssched-cmd. >That is absolutely true but I've understood that the system worked OK in the past. And AFAIK (please correct me if I am wrong) the missing command was simply ignored. And I think that the lines you quoted do not explain a shutdown while the line I quoted does. wolfy -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://alioth-lists.debian.net/pipermail/nut-upsuser/attachments/20200111/97b46c15/attachment-0001.html>