[Nut-upsuser] The system doesn't shutdown

Tue Oct 27 22:00:32 UTC 2015

Beautiful! The shutdown succeeded. Thank you very much. However there was
no any notification on desktop at all. Only in journalctl. Here it is:

Oct 27 23:38:11 i7 upsmon[2224]: UPS myups at localhost on battery
Oct 27 23:38:11 i7 upssched[2244]: Timer daemon started
Oct 27 23:38:11 i7 upssched[2244]: New timer: two-minute-warning-timer (5
seconds)
Oct 27 23:38:11 i7 upssched[2244]: New timer: one-minute-warning-timer (65
seconds)
Oct 27 23:38:11 i7 upssched[2244]: New timer: shutdown-timer (125 seconds)
Oct 27 23:38:16 i7 upssched[2244]: Event: two-minute-warning-timer
Oct 27 23:38:16 i7 upssched-cmd[2246]: Calling upssched-cmd
two-minute-warning-timer
Oct 27 23:38:16 i7 upssched-cmd[2247]: Two minute warning timeout reached
Oct 27 23:39:16 i7 upssched[2244]: Event: one-minute-warning-timer
Oct 27 23:39:16 i7 upssched-cmd[2254]: Calling upssched-cmd
one-minute-warning-timer
Oct 27 23:39:16 i7 upssched-cmd[2255]: One minute warning timeout reached
Oct 27 23:40:16 i7 upssched[2244]: Event: shutdown-timer
Oct 27 23:40:16 i7 upssched-cmd[2263]: Calling upssched-cmd shutdown-timer
Oct 27 23:40:16 i7 upssched-cmd[2264]: Shutdown timer reached: Calling
upsmon -c fsd
Oct 27 23:40:16 i7 upsmon[2224]: Signal 10: User requested FSD
Oct 27 23:40:16 i7 upsd[2221]: Client upsmaster@::1 set FSD on UPS [myups]
Oct 27 23:40:16 i7 upsmon[2224]: Executing automatic power-fail shutdown
Oct 27 23:40:16 i7 upsmon[2224]: Auto logout and shutdown proceeding
Oct 27 23:40:21 i7 upsmon.conf[2277]: SHUTDOWNCMD calling /sbin/shutdown to
shut down system
# and so on...

One thing that caught my attention: I have disabled the
nut-delayed-ups-shutdown service one day ago (many reboots since then) in
order to avoid the effect of the UPS self-shutting on normal reboot. After
this last test right now, and after the system shut down completely I
plugged the cord in and booted. However during the boot process the UPS
powered off while the power was on and the boot was not yet complete
(argh...). Then in a second or two, without me doing anything, the UPS got
back ON and I started the computer - this time the boot was clean, without
power off.

It seems this solves the problem to have a clean reboot without UPS
powering off. However it looks like a misbehavior after all because the UPS
is not supposed to shutdown if the nut-delayed-ups-shutdown service is
disabled, right? Or is anything else shutting down the UPS itself?

Here is the nut-journal from after the boot:

        Previous complete boot through shutdown
Oct 27 23:41:27 i7 systemd-journal[519]: Time spent on flushing to /var is
686.451ms for 1311 entries.
        Current boot
Oct 27 23:43:09 i7 upsdrvctl[2013]: Using subdriver: MGE HID 1.32
Oct 27 23:43:10 i7 upsdrvctl[2013]: Network UPS Tools - Generic HID driver
0.38 (2.7.1)
Oct 27 23:43:10 i7 upsdrvctl[2013]: USB communication driver 0.32
Oct 27 23:43:11 i7 upsdrvctl[2013]: Network UPS Tools - UPS driver
controller 2.7.1
Oct 27 23:43:11 i7 upsd[2155]: fopen /var/lib/ups/upsd.pid: No such file or
directory
Oct 27 23:43:11 i7 upsd[2155]: listening on ::1 port 3493
Oct 27 23:43:11 i7 upsd[2155]: listening on ::1 port 3493
Oct 27 23:43:11 i7 upsd[2155]: listening on 127.0.0.1 port 3493
Oct 27 23:43:11 i7 upsd[2155]: Connected to UPS [myups]: usbhid-ups-myups
Oct 27 23:43:11 i7 upsd[2155]: listening on 127.0.0.1 port 3493
Oct 27 23:43:11 i7 upsd[2155]: Connected to UPS [myups]: usbhid-ups-myups
Oct 27 23:43:11 i7 upsd[2156]: Startup successful
Oct 27 23:43:11 i7 upsmon[2157]: fopen /var/run/upsmon.pid: No such file or
directory
Oct 27 23:43:11 i7 upsmon[2157]: UPS: myups at localhost (master) (power value
1)
Oct 27 23:43:11 i7 upsmon[2157]: Using power down flag file
/etc/ups/killpower
Oct 27 23:43:11 i7 upsmon[2158]: Startup successful
Oct 27 23:43:11 i7 upsd[2156]: User upsmaster@::1 logged into UPS [myups]

Another thing (a bit of a side question, I hope it is ok to ask): During
the last 3-4 months (using simply KNotify about UPS connection states) I
noticed that sometimes unpredictably a notification appears that the USB
connection to the UPS is lost and a few seconds later another notification
appears that the connection is restored. And this repeats to infinity. The
only way to get out of it is to shutdown the machine, turn off the UPS,
unplug the power and restart everything again. I had no luck finding a
pattern when and why it happens. This has never happened before. The
batteries are fairly new (changed late January 2015) and there have been no
power outages since then (maybe one or two for 2-3 minutes only). However I
notice that a short power off test (like the one I just did) makes the
battery fall from 100% to 85% for less than a minute and then charges very
long to reach 100% again. A friend said he has noticed similar peculiarity
with other MGE UPS units. Can you share thoughts on this? I hope you don't
mind me asking.

Thanks again!

---
George
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.alioth.debian.org/pipermail/nut-upsuser/attachments/20151028/9e6a0d5a/attachment-0001.html>