This topic has been marked solved and closed to new posts due to inactivity. We hope you'll join the conversation by posting to an open topic or starting a new one.
Does the UPS status eventually go back to an expected value? Can be used normally now?
-Amidala
Having not changed anything since yesterday, I can now answer this.
On the RN316, it stays in a bad state;
System/Overview -> UPS Warning
System/Performance -> Value1200E, Battery Charge: ? %, 0 min.
System/Power/UPS -> UPS_RAWSTATUS_WAIT
@LAST email & log in NV+ shown Comms Error @19:56 yesterday, with no OK message after, so it has been in that bad state for 13 hours.@19:56 yesterday, with no OK message after, so it has been in that bad state for 13 hours.
NV+ shows:
Remote Error, Battery charge: 0%, 0 minutes Out of Spec
RAIDar (6.1) shows Healthy for the 316, even tho the Frontview System/Overview shows UPS Warning; NV+ RAIDaar status "Remote Error, Battery charge: 0%, 0 minutes".
System/Overview & System/Power/UPS show a yellow dot, System/Performance a red dot.
Update finshed 17:10, RN316 UPS status looks normal.
NV+ status went to normal a little later, ?~30s.
RAIDar took a few minutes to clear NV+ UPS error.
17:20 Changed UPS setting to AUTO (from 30%) - mention this re log below.
Extract of 'UPS' from system.log:
Nov 18 17:07:31 ME-NAS-316A usbhid-ups[3798]: Startup successful Nov 18 17:07:31 ME-NAS-316A upsd[3800]: Startup successful Nov 18 17:07:32 ME-NAS-316A upsmon[3812]: Startup successful Nov 18 17:07:32 ME-NAS-316A upsd[3800]: User monuser@::1 logged into UPS [UPS] Nov 18 17:07:32 ME-NAS-316A upsd[3800]: User monuser@::1 logged into UPS [UPS] Nov 18 17:07:32 ME-NAS-316A upsd[3800]: User monuser@::1 logged into UPS [UPS] Nov 18 17:09:03 ME-NAS-316A upsd[3800]: User monuser@192.168.1.10 logged into UPS [UPS] Nov 18 17:09:03 ME-NAS-316A upsd[3800]: User monuser@192.168.1.10 logged into UPS [UPS] Nov 18 17:09:03 ME-NAS-316A upsd[3800]: User monuser@192.168.1.10 logged into UPS [UPS] Nov 18 17:20:46 ME-NAS-316A upsmon[3813]: Signal 15: exiting Nov 18 17:20:46 ME-NAS-316A upsd[3800]: User monuser@::1 logged out from UPS [UPS] Nov 18 17:20:46 ME-NAS-316A upsd[3800]: User monuser@::1 logged out from UPS [UPS] Nov 18 17:20:46 ME-NAS-316A upsd[3800]: User monuser@::1 logged out from UPS [UPS] Nov 18 17:20:46 ME-NAS-316A usbhid-ups[3798]: Signal 15: exiting Nov 18 17:20:46 ME-NAS-316A upsd[3800]: Can't connect to UPS [UPS] (usbhid-ups-UPS): No such file or directory Nov 18 17:20:46 ME-NAS-316A upsd[3800]: Can't connect to UPS [UPS] (usbhid-ups-UPS): No such file or directory Nov 18 17:20:46 ME-NAS-316A upsd[3800]: Can't connect to UPS [UPS] (usbhid-ups-UPS): No such file or directory Nov 18 17:20:46 ME-NAS-316A upsd[3800]: Can't connect to UPS [UPS] (usbhid-ups-UPS): No such file or directory Nov 18 17:20:46 ME-NAS-316A upsd[3800]: Can't connect to UPS [UPS] (usbhid-ups-UPS): No such file or directory Nov 18 17:20:46 ME-NAS-316A upsd[3800]: mainloop: Interrupted system call Nov 18 17:20:46 ME-NAS-316A upsd[3800]: Signal 15: exiting Nov 18 17:20:46 ME-NAS-316A usbhid-ups[6556]: Startup successful Nov 18 17:20:46 ME-NAS-316A upsd[6558]: Startup successful Nov 18 17:20:46 ME-NAS-316A upsmon[6560]: Startup successful Nov 18 17:20:46 ME-NAS-316A upsd[6558]: User monuser@::1 logged into UPS [UPS] Nov 18 17:20:46 ME-NAS-316A upsd[6558]: User monuser@::1 logged into UPS [UPS] Nov 18 17:20:46 ME-NAS-316A upsd[6558]: User monuser@::1 logged into UPS [UPS] Nov 18 17:20:54 ME-NAS-316A upsd[6558]: User monuser@192.168.1.10 logged into UPS [UPS] Nov 18 17:20:54 ME-NAS-316A upsd[6558]: User monuser@192.168.1.10 logged into UPS [UPS] Nov 18 17:20:54 ME-NAS-316A upsd[6558]: User monuser@192.168.1.10 logged into UPS [UPS]
RN316 Fri Nov 18 2016 19:07:52 System: Error communicating with UPS 'UPS' ().
Various frontview views look normal, but this is 7min later after AFK.
However I did get an email from the 316. Note NO followup email or log saying Comms OK, even tho above looks normal. (yes I refreshed frontview)
NV+ Health: UPS 1 Remote Error, Battery charge: 0%, 0 minutes Out of Spec
NV+ Log: Fri Nov 18 19:07:52 EST 2016 UPS Communication error.
System log following above log, same data stale messages:
Nov 18 17:21:42 ME-NAS-316A dbus[3338]: [system] Activating service name='org.opensuse.Snapper' (using servicehelper) Nov 18 17:21:42 ME-NAS-316A dbus[3338]: [system] Successfully activated service 'org.opensuse.Snapper' Nov 18 18:07:41 ME-NAS-316A dbus[3338]: [system] Activating service name='org.opensuse.Snapper' (using servicehelper) Nov 18 18:07:41 ME-NAS-316A dbus[3338]: [system] Successfully activated service 'org.opensuse.Snapper' Nov 18 18:16:59 ME-NAS-316A apache_access[4297]: Suppressed 597 duplicate messages Nov 18 18:16:59 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /dbbroker HTTP/1.1" 200 Nov 18 18:17:01 ME-NAS-316A CRON[12561]: pam_unix(cron:session): session opened for user root by (uid=0) Nov 18 18:17:01 ME-NAS-316A CRON[12568]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Nov 18 18:17:01 ME-NAS-316A CRON[12561]: pam_unix(cron:session): session closed for user root Nov 18 19:07:42 ME-NAS-316A dbus[3338]: [system] Activating service name='org.opensuse.Snapper' (using servicehelper) Nov 18 19:07:42 ME-NAS-316A dbus[3338]: [system] Successfully activated service 'org.opensuse.Snapper' Nov 18 19:07:49 ME-NAS-316A upsd[6558]: Data for UPS [UPS] is stale - check driver Nov 18 19:07:52 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:07:54 ME-NAS-316A msmtpq[17345]: mail for [ -C /etc/msmtprc michael...com.au --timeout=60 ] : send was successful Nov 18 19:07:57 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:07:57 ME-NAS-316A upsd[6558]: User monuser@192.168.1.10 logged out from UPS [UPS] Nov 18 19:08:02 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:08:07 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale ...
Nov 18 19:08:57 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:09:02 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:09:06 ME-NAS-316A apache_access[4297]: Suppressed 509 duplicate messages Nov 18 19:09:06 ME-NAS-316A apache_access[4297]: 192.168.1.15 "GET /stimg?type=volume&name=&value=oper&period=1_hour&width=1019&height=275&back=ffffff&randParam=0.5404600522758055 HTTP/1.1" 200 Nov 18 19:09:06 ME-NAS-316A apache_access[4297]: 192.168.1.15 "GET /stimg?type=volume&name=&value=utilizn&period=1_hour&width=1019&height=261&back=ffffff&randParam=0.6902996265104178 HTTP/1.1" 200 Nov 18 19:09:06 ME-NAS-316A apache_access[4297]: 192.168.1.15 "GET /stimg?type=network&name=&value=pkts&period=1_hour&width=1019&height=303&back=ffffff&proto=&randParam=0.013336750715785883 HTTP/1.1" 200 Nov 18 19:09:06 ME-NAS-316A apache_access[4297]: 192.168.1.15 "GET /stimg?type=temperature&name=&value=deg&period=1_hour&width=1019&height=275&back=ffffff&randParam=0.391255569966801 HTTP/1.1" 200 Nov 18 19:09:07 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /dbbroker HTTP/1.1" 200 Nov 18 19:09:07 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:09:12 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale ...
Nov 18 19:11:57 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:12:02 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:12:03 ME-NAS-316A apache_access[4297]: Suppressed 38 duplicate messages Nov 18 19:12:03 ME-NAS-316A apache_access[4297]: 192.168.1.15 "GET /stimg?type=volume&name=&value=oper&period=1_hour&width=1019&height=275&back=ffffff&randParam=0.24818174261631676 HTTP/1.1" 200 Nov 18 19:12:03 ME-NAS-316A apache_access[4297]: 192.168.1.15 "GET /stimg?type=volume&name=&value=utilizn&period=1_hour&width=1019&height=261&back=ffffff&randParam=0.07640820144507465 HTTP/1.1" 200 Nov 18 19:12:03 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /dbbroker HTTP/1.1" 200 Nov 18 19:12:03 ME-NAS-316A apache_access[4297]: 192.168.1.15 "GET /stimg?type=network&name=&value=pkts&period=1_hour&width=1019&height=303&back=ffffff&proto=&randParam=0.5078713449378665 HTTP/1.1" 200 Nov 18 19:12:03 ME-NAS-316A apache_access[4297]: 192.168.1.15 "GET /stimg?type=temperature&name=&value=deg&period=1_hour&width=1019&height=275&back=ffffff&randParam=0.47147658146671056 HTTP/1.1" 200 Nov 18 19:12:05 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /dbbroker HTTP/1.1" 200 Nov 18 19:12:07 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:12:09 ME-NAS-316A apache_access[4297]: Suppressed 8 duplicate messages Nov 18 19:12:09 ME-NAS-316A apache_access[4297]: 192.168.1.15 "GET /stimg?type=volume&name=&value=oper&period=1_hour&width=1019&height=275&back=ffffff&randParam=0.9777447772761799 HTTP/1.1" 200 Nov 18 19:12:09 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /dbbroker HTTP/1.1" 200 Nov 18 19:12:12 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:12:14 ME-NAS-316A apache_access[4297]: Suppressed 4 duplicate messages Nov 18 19:12:14 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /fsbroker/ HTTP/1.1" 200 Nov 18 19:12:14 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /dbbroker HTTP/1.1" 200 Nov 18 19:12:14 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /fwbroker HTTP/1.1" 200 Nov 18 19:12:14 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /dbbroker HTTP/1.1" 200 Nov 18 19:12:15 ME-NAS-316A apache_access[4297]: Suppressed 6 duplicate messages Nov 18 19:12:15 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /fwbroker HTTP/1.1" 200 Nov 18 19:12:16 ME-NAS-316A apache_access[4297]: 192.168.1.15 "POST /dbbroker HTTP/1.1" 200 Nov 18 19:12:17 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:12:22 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale ...
Nov 18 19:13:12 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:13:17 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:13:21 ME-NAS-316A dbus[3338]: [system] Activating service name='org.opensuse.Snapper' (using servicehelper) Nov 18 19:13:21 ME-NAS-316A dbus[3338]: [system] Successfully activated service 'org.opensuse.Snapper' Nov 18 19:13:22 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale Nov 18 19:13:27 ME-NAS-316A upsmon[6561]: Poll UPS [UPS@localhost] failed - Data stale
So I upgraded to the beta version as well, and it also cycles between okay and failed.
I have a Cyberpower CST135XLU and a RN104.
Logs are as follows:
Fri Nov 18 2016 6:29:23
System: Error communicating with UPS 'UPS' ().
Fri Nov 18 2016 6:29:08
System: Communication with UPS 'UPS' () is OK.
Fri Nov 18 2016 5:48:47
System: Error communicating with UPS 'UPS' ().
Fri Nov 18 2016 5:48:32
System: Communication with UPS 'UPS' () is OK.
Fri Nov 18 2016 5:08:07
System: Error communicating with UPS 'UPS' ().
Fri Nov 18 2016 5:07:53
System: Communication with UPS 'UPS' () is OK.
Fri Nov 18 2016 4:27:32
System: Error communicating with UPS 'UPS' ().
Fri Nov 18 2016 4:27:12
System: Communication with UPS 'UPS' () is OK.
Fri Nov 18 2016 3:46:57
System: Error communicating with UPS 'UPS' ().
Fri Nov 18 2016 3:46:37
System: Communication with UPS 'UPS' () is OK.
Fri Nov 18 2016 3:06:21
System: Error communicating with UPS 'UPS' ().
Fri Nov 18 2016 3:06:06
System: Communication with UPS 'UPS' () is OK.
Fri Nov 18 2016 2:25:46
System: Error communicating with UPS 'UPS' ().
Fri Nov 18 2016 2:25:26
System: Communication with UPS 'UPS' () is OK.
Fri Nov 18 2016 1:45:00
System: Error communicating with UPS 'UPS' ().
Fri Nov 18 2016 1:44:45
System: Communication with UPS 'UPS' () is OK.
Fri Nov 18 2016 1:04:25
System: Error communicating with UPS 'UPS' ().
Fri Nov 18 2016 1:04:05
System: Communication with UPS 'UPS' () is OK.
Fri Nov 18 2016 0:23:40
System: Error communicating with UPS 'UPS' ().
Fri Nov 18 2016 0:23:25
System: Communication with UPS 'UPS' () is OK.
Thu Nov 17 2016 23:43:05
System: Error communicating with UPS 'UPS' ().
Thu Nov 17 2016 23:42:50
System: Communication with UPS 'UPS' () is OK.
Thu Nov 17 2016 23:02:29
System: Error communicating with UPS 'UPS' ().
Thu Nov 17 2016 23:02:09
System: Communication with UPS 'UPS' () is OK.
Thu Nov 17 2016 22:21:49
System: Error communicating with UPS 'UPS' ().
Thu Nov 17 2016 22:21:34
System: Communication with UPS 'UPS' () is OK.
Thu Nov 17 2016 21:41:09
System: Error communicating with UPS 'UPS' ().
Thu Nov 17 2016 21:40:49
System: Communication with UPS 'UPS' () is OK.
Thu Nov 17 2016 21:00:19
System: Error communicating with UPS 'UPS' ().
Thu Nov 17 2016 21:00:04
System: Communication with UPS 'UPS' () is OK.
Thu Nov 17 2016 20:19:38
System: Error communicating with UPS 'UPS' ().
Thu Nov 17 2016 20:19:18
System: Communication with UPS 'UPS' () is OK.
Thu Nov 17 2016 19:38:43
System: Error communicating with UPS 'UPS' ().
Thu Nov 17 2016 19:34:20
System: New USB UPS detected. Manufacturer: CPS, Model: CST135XLU, Serial: CR7EX2003225.
Thu Nov 17 2016 19:34:06
System: USB UPS removed. Manufacturer: CPS, Model: CST135XLU, Serial: CR7EX2003225.
Thu Nov 17 2016 19:33:34
System: Firmware was upgraded to 6.6.1-T200.
As you can see I removed the UPS and then reconnected it.
So I am back to not being able to use UPS monitoring 😞
... RN316 logs sent, let me know if you want NV+ logs, it seemed to me the NV+ frontview reported UPS status more promptly than RN316.
Here is the recent NV+ frontview logs:
Sat Nov 19 14:11:43 EST 2016 UPS Communication error. Sat Nov 19 14:11:22 EST 2016 Communication with UPS OK. Sat Nov 19 12:39:07 EST 2016 UPS Communication error. Sat Nov 19 10:25:18 EST 2016 Communication with UPS OK. Sat Nov 19 10:25:15 EST 2016 Communication with UPS OK. Sat Nov 19 10:23:59 EST 2016 System is up. Sat Nov 19 10:22:59 EST 2016 Cannot communicate with UPS. Sat Nov 19 10:22:51 EST 2016 UPS Communication error. Sat Nov 19 10:18:00 EST 2016 UPS is shutting down system. Sat Nov 19 10:18:00 EST 2016 UPS forcing shutdown. Sat Nov 19 10:17:55 EST 2016 UPS battery is low; system will shutdown soon. Sat Nov 19 10:16:25 EST 2016 UPS is on battery power. Sat Nov 19 10:11:53 EST 2016 Communication with UPS OK. Sat Nov 19 07:03:16 EST 2016 Backup finished. [Job 001] Sat Nov 19 02:49:54 EST 2016 UPS Communication error. Sat Nov 19 02:49:39 EST 2016 Communication with UPS OK. Fri Nov 18 23:45:16 EST 2016 UPS Communication error. Fri Nov 18 23:45:05 EST 2016 Communication with UPS OK. Fri Nov 18 22:12:49 EST 2016 UPS Communication error. Fri Nov 18 22:12:29 EST 2016 Communication with UPS OK. Fri Nov 18 19:07:52 EST 2016 UPS Communication error. Fri Nov 18 17:20:55 EST 2016 Communication with UPS OK. Fri Nov 18 17:20:49 EST 2016 UPS Communication error. Fri Nov 18 17:09:02 EST 2016 Communication with UPS OK. Fri Nov 18 00:50:06 EST 2016 UPS Communication error. Fri Nov 18 00:49:50 EST 2016 Communication with UPS OK. Thu Nov 17 23:17:35 EST 2016 UPS Communication error. Thu Nov 17 23:17:14 EST 2016 Communication with UPS OK. Thu Nov 17 20:12:51 EST 2016 UPS Communication error. Thu Nov 17 20:12:35 EST 2016 Communication with UPS OK. Thu Nov 17 18:40:20 EST 2016 UPS Communication error. Thu Nov 17 18:40:09 EST 2016 Communication with UPS OK.
For the record, I have just bought an APC 700VA/405W (UK) UPS, and connected it to my ReadyNAS 104 (v6.6.0) by USB cable (and mains cable obviously). The UPS was automatically recognised correctly. After 16 hours charging, I set the Shutdown Threshhold to 80%, for testing, and turned the power to the UPS OFF. Results are:
1. After about quarter of an hour, the NAS turned itself off abruptly. There was no "Graceful Shutdown", it just powered itself off within a second or so. The UPS continued to supply mains power, so it wasn't the UPS powering off the mains supply.
2. There were no emails about anything. Nothing to say the NAS/UPS was on battery power, nothing about an imminent shutdow, and nothing to say the NAS had shutdown.
3 On restart, there were no messages in the Logs about anything either.
I don't think anyone has pointed out the hard shutdown, which I find worrying. It should do a graceful shutdown.
Model: RN10400|ReadyNAS 100 Series 4- Bay (Diskless)
For the record, I have just bought an APC 700VA/405W (UK) UPS, and connected it to my ReadyNAS 104 (v6.6.0) by USB cable (and mains cable obviously). The UPS was automatically recognised correctly. After 16 hours charging, I set the Shutdown Threshhold to 80%, for testing, and turned the power to the UPS OFF. Results are:
It might be worthwhile to try this test again w/o connecting the NAS to the UPS power (but still connecting the USB cable). You'd need some other load on the UPS (perhaps a lamp???)
It might be worthwhile to try this test again w/o connecting the NAS to the UPS power (but still connecting the USB cable). You'd need some other load on the UPS (perhaps a lamp???)
Not sure what this idea will achieve? Is it to test if the UPS powers off the NAS? (if not the NAS will shutdown from the USB interface). I had a voltmeter on another socket and the voltage remained at 230V afterwards, although I didn't watch the meter at the crucial point of shutdown. Let me know.
Not sure what this idea will achieve? Is it to test if the UPS powers off the NAS? (if not the NAS will shutdown from the USB interface). I had a voltmeter on another socket and the voltage remained at 230V afterwards, although I didn't watch the meter at the crucial point of shutdown. Let me know.
The idea is to test the UPS communication path without letting the NAS power down.
The idea is to test the UPS communication path without letting the NAS power down.
OK, just tried that test. The NAS was powered direct from the mains but still connected to the UPS by USB. I turned off the socket that powers the UPS so it went on to battery power. I had set the Shutdown Threshhold to 90%, so the UPS (loaded by my network switch in fact) carried on for about 5 minutes and then the NAS abruptly turned itself off (a hard shutdown taking well under a second). This shows it is not the NAS losing its power from the UPS, but something to do with either the UPS or NAS firmware. I did not receive my usual email which I get when the NAS gracefully shuts down, nor any other emails, and there is nothing in the Logs either. It appears to me that there is a bug in NAS v6.6.0, considering the other problems above, which is not generating any messages nor a graceful shutdown.
Model: RN10400|ReadyNAS 100 Series 4- Bay (Diskless)
While I agree it looks likely to be the same as my problem, you may want to check the frontview power/ups display when you test, AND set the threshold to say 50%, at 90% it may get the critical shutdown message straight away. At 50% it, if it's working, will have time to notify etc.
From my testing, once the battery gets critical, the NAS shuts down promptly.
While I agree it looks likely to be the same as my problem, you may want to check the frontview power/ups display when you test, AND set the threshold to say 50%, at 90% it may get the critical shutdown message straight away. At 50% it, if it's working, will have time to notify etc.
From my testing, once the battery gets critical, the NAS shuts down promptly.
Hi. I have tested at 80%, when the NAS ran for 20 minutes with a fully charged battery. This is ample time to settle down. And the NAS does shut down promptly once the threshold is triggered, the problem being that it crashes out with a hard shutdown, so endangering any data and being no better than what happens when the NAS is powered off the mains and a power cut occurs.
