I have a ReadyNAS 102 running 6.6.1, connected to a CyberPower CP850PCFLCD UPS. All normal operation until this morning. I have tested this combination *multiple* times, and I can unplug the UPS from the wall, and the ReadyNAS can communicate with it and continue to run temporarily (all since the 6.6.1 firmware, as the earlier firmware had some problems communicating with UPS systems).
At 6:30am today this appeared in the frontview logs:
Fri May 26 2017 6:30:09 System: UPS UPS () is on battery power.
Then this:
Fri May 26 2017 6:30:11 System: Error communicating with UPS 'UPS' ().
I got both alerts by email as well. When I came into the room about ten minutes later, the NAS was shut down. I powered it up and it booted normally. I have since tested the operation of the UPS by unplugging it and it works fine (NAS is aware that the UPS is running on battery power). Here are the detailed system logs from this morning's incident, with my email address removed. It looks like comms failed with the UPS, and the ReadyNAS shut itself down as a precaution:
May 26 06:30:09 NAS usbhid-ups[5287]: libusb_get_interrupt: Input/output error
May 26 06:30:11 NAS msmtpq[8317]: mail for [ -C /etc/msmtprc EMAIL --timeout=60 ] : send was successful
May 26 06:30:11 NAS upsd[5289]: Data for UPS [UPS] is stale - check driver
May 26 06:30:11 NAS upsmon[5295]: Poll UPS [UPS@localhost] failed - Data stale
May 26 06:30:12 NAS msmtpq[8336]: mail for [ -C /etc/msmtprc EMAIL --timeout=60 ] : send was successful
May 26 06:30:13 NAS upsmon[5295]: Poll UPS [UPS@localhost] failed - Data stale
May 26 06:30:15 NAS upsmon[5295]: Poll UPS [UPS@localhost] failed - Data stale
May 26 06:30:17 NAS upsmon[5295]: Poll UPS [UPS@localhost] failed - Data stale
May 26 06:30:19 NAS upsmon[5295]: Poll UPS [UPS@localhost] failed - Data stale
May 26 06:30:21 NAS upsmon[5295]: Poll UPS [UPS@localhost] failed - Data stale
May 26 06:30:23 NAS upsmon[5295]: Poll UPS [UPS@localhost] failed - Data stale
May 26 06:30:25 NAS upsmon[5295]: Poll UPS [UPS@localhost] failed - Data stale
May 26 06:30:25 NAS upsd[5289]: Client monuser@::1 set FSD on UPS [UPS]
May 26 06:30:25 NAS upsmon[5295]: Executing automatic power-fail shutdown
May 26 06:31:28 NAS wsdd2[2032]: Terminated received.
May 26 06:31:28 NAS wsdd2[2032]: terminating.
May 26 06:31:28 NAS afpd[7627]: AFP Server shutting down
May 26 06:31:28 NAS cnid_metad[7628]: shutting down on SIGTERM
May 26 06:31:28 NAS netatalk[7626]: Netatalk AFP server exiting
May 26 06:31:29 NAS upsd[5289]: mainloop: Interrupted system call
May 26 06:31:29 NAS upsd[5289]: Signal 15: exiting
May 26 06:31:29 NAS usbhid-ups[5287]: Signal 15: exiting
May 26 06:31:30 NAS mysqld[2616]: 170526 6:31:30 [Note] /usr/sbin/mysqld: Normal shutdown
May 26 06:31:30 NAS mysqld[2616]:
May 26 06:31:30 NAS mysqld[2616]: 170526 6:31:30 [Note] Event Scheduler: Purging the queue. 0 events
May 26 06:31:31 NAS mysqld[2616]: 170526 6:31:31 InnoDB: Starting shutdown...
May 26 06:31:34 NAS mysqld[2616]: 170526 6:31:34 InnoDB: Shutdown completed; log sequence number 1595685
May 26 06:31:34 NAS mysqld[2616]: 170526 6:31:34 [Note] /usr/sbin/mysqld: Shutdown complete
May 26 06:31:34 NAS mysqld[2616]:
May 26 06:31:34 NAS mysqld_safe[8433]: mysqld from pid file /var/run/mysqld/mysqld.pid ended
May 26 06:31:44 NAS sshd[2067]: Received signal 15; terminating.
May 26 06:31:44 NAS nmbd[2104]: [2017/05/26 06:31:44.772910, 0] ../source3/nmbd/nmbd.c:58(terminate)
May 26 06:31:44 NAS nmbd[2104]: Got SIGTERM: going down...
May 26 06:31:44 NAS avahi-daemon[2034]: Got SIGTERM, quitting.
May 26 06:31:44 NAS avahi-daemon[2034]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.0.70.
May 26 06:31:44 NAS avahi-daemon[2034]: avahi-daemon 0.6.32 exiting.
May 26 06:31:46 NAS rpcbind[2081]: rpcbind terminating on signal. Restart with "rpcbind -w"
May 26 06:31:46 NAS connmand[2027]: Terminating
May 26 06:31:46 NAS connmand[2027]: Remove interface eth0 [ ethernet ]
May 26 06:31:46 NAS connmand[2027]: eth0 {remove} index 2
May 26 06:31:46 NAS connmand[2027]: Exit
There are no other occurences of "UPS" in the system.log going back to May 14.
The NAS won't normally shut down just because it lost communications with the UPS. But the last valid communication it had said it was on battery power, and that appears to be why it shut down. There may have been a short disruption in your power that the UPS did not react to well. Your test seems adaquate to say you don't have a permanent problem and I wouldn't worry about it unless it happens again.
Thank you Sandshark. Appreciate the info and I'll keep an eye on it. I was happy to see that it shut down gracefully. I have on and offsite backups of everything just in case.
