Re: ReadyNASOS 6.6.0 (RC2) UPS problems

TOMA1 · ‎2016-09-26

Still having UPS problems. 6.6.0 (RC2)

from status.log

[16/09/26 02:13:33 MST] notice:system:LOGMSG_ADD_LOCAL_UPS New UPS on PortUSB detected. Manufacturer: CPS, Model: CST1300ALU, Serial: ############.

from system.log

Sep 26 14:10:18 rNAS4-VM upsmon[5487]: Poll UPS [UPS@localhost] failed - Data stale
Sep 26 14:10:23 rNAS4-VM upsmon[5487]: Poll UPS [UPS@localhost] failed - Data stale
Sep 26 14:10:28 rNAS4-VM upsmon[5487]: Poll UPS [UPS@localhost] failed - Data stale

Sep 26 14:10:29 rNAS4-VM upsd[5475]: Send ping to UPS [UPS] failed: Resource temporarily unavailable

Sep 26 14:10:38 rNAS4-VM upsmon[5487]: Poll UPS [UPS@localhost] failed - Server disconnected
Sep 26 14:10:48 rNAS4-VM upsmon[5487]: Set username on [UPS@localhost] failed: Server disconnected
Sep 26 14:10:53 rNAS4-VM upsmon[5487]: Poll UPS [UPS@localhost] failed - Driver not connected

Sep 26 15:54:05 rNAS4-VM upsmon[5487]: Set username on [UPS@localhost] failed: Server disconnected
Sep 26 15:54:10 rNAS4-VM upsmon[5487]: Poll UPS [UPS@localhost] failed - Driver not connected

mdgm-ntgr · ‎2016-09-26

When did these problems start and on which firmware?

Is this in a VM (I notice your hostname is rNAS4-VM) or on an actual ReadyNAS unit?

TOMA1 · ‎2016-09-26

These are logs from a 6.6.0 (RC2) 104 box (actual ReadyNAS unit). Really haven't had any luck using the Cyber Power UPS on any of the 6.6.0 releases

Just read the release notes on 6.6.0 (RC2) and saw the “35. [RC2] Fixed UPS support.” and thought I'd try again.

Setup on the 6.6.0 (RC2) box, using the Cyber Power as a remote UPS on a RN104 running 6.4.2 works fine.

Leia · ‎2016-09-29

Could you please send the log follow this link? And Attn: Leia

StephenB · ‎2016-09-29

@TOMA1 wrote:

These are logs from a 6.6.0 (RC2) 104 box (actual ReadyNAS unit). Really haven't had any luck using the Cyber Power UPS on any of the 6.6.0 releases

My Cyberpower is working with my RN102 (also running 6.6.0-RC2). RC1 reported it as working from the web UI, but there were USB errors in the log.

TOMA1 · ‎2016-09-29

Logs sent.

mdgm-ntgr · ‎2016-09-29

Do you still see this on the production release (local update only at this stage)? If so, please send through another set of logs.

TOMA1 · ‎2016-09-29

Steps taken:

1) Upgraded to 6.6.0 release (from 6.6.0 RC2).

2) Downloaded logs.

3) Rebooted system (just to be on the safe side).

4) Downloaded logs.

All seemed okay.

Checked system several hours later and saw errors again.

5) Downloaded logs.

Submitted logs from steps 4 and 5.

powellandy1 · ‎2016-10-02

Hi

I keep having a UPS problem as well with 6.6.0 production. Never tried the betas/RCs but was fine on all previous versions.

Unit is ReadyNAS312, UPS is Cyberpower Value 800.

Logs uploaded. If this is a different issue then let me know and i'll start a new thread.

THanks

Andy

powellandy1 · ‎2016-10-08

Bump!!

JennC · ‎2016-10-08

Hello powellandy1,

I suggest you contact support, you have lifetime CHAT support for your NAS, it shows on your records.

Regards,

powellandy1 · ‎2016-10-08

Thanks.

Just to be clear (and honest) - I didn't own it from new - am I still entitled to free chat support??

Also - again just to be clear - it worked fine in all OS versions from 6.2.5 to 6.5.2 - nothing has changed other than the upgrade to 6.6.0.

Cheers

Andy

JennC · ‎2016-10-08

Hello powellandy1,

It is registered to your name and was registered back in Feb 2016 so you should be able to get the support.

Regards,

powellandy1 · ‎2016-10-09

Thanks, they have escalated to L3. Will update thread when know more.

ShoGinn · ‎2016-10-09

Ever since upgrading to 6.6.0 I also have been getting all the same errors as above. Seems to be a common issue with the NUT server on other platforms. I have tried all USB ports on the box to no avail.

I'll follow this thread in hopes they can figure it out.

Amazing how a quick patch like this can wreck something that used to work 😞

mdgm-ntgr · ‎2016-10-09

ShoGinn, do you also have a CyberPower UPS?

ShoGinn · ‎2016-10-09

I do have a cyberpower.

device.mfr: CPS

device.model: CST135XLU

Thats from UPSC.. seems to always disconnect now.

TOMA1 · ‎2016-10-09

Just FYI

Connected an APC UPS to the unit also. When the APC was connected the CPS unit showed "on line power" for a while (prior was UPS_RAWSTATUS_WAIT). After an hour or so this was the status.

StephenB · ‎2016-10-09

My CyberPower 1350 and 1500 are both working with 6.6.0

mdgm-ntgr · ‎2016-10-09

@StephenB wrote:

My CyberPower 1350 and 1500 are both working with 6.6.0

Which model ReadyNAS is this with?

How long did you test for? The problem could take about half an hour or so to see.

Would be good to get SDM for more units for comparison.

StephenB · ‎2016-10-10

The 1500 is connected to my RN202, and the 1350 is connected to my RN102.

I can send you logs if that is useful.

ShoGinn · ‎2016-10-11

Thats interesting that yours works..

Before upgrading to 6.6.0 my 1350 connected to my RN104 worked perfect.

● nut-monitor.service - Network UPS Tools - power device monitor and shutdown controller
   Loaded: loaded (/lib/systemd/system/nut-monitor.service; disabled; vendor preset: disabled)
   Active: active (running) since Mon 2016-10-10 12:06:02 PDT; 23h ago
  Process: 2589 ExecStart=/sbin/upsmon (code=exited, status=0/SUCCESS)
 Main PID: 2591 (upsmon)
   CGroup: /system.slice/nut-monitor.service
           ├─2590 /lib/nut/upsmon
           └─2591 /lib/nut/upsmon

Oct 11 11:37:02 ReadyNAS upsmon[2591]: Poll UPS [UPS@localhost] failed - Driver not connected
Oct 11 11:37:12 ReadyNAS upsmon[2591]: Set username on [UPS@localhost] failed: Server disconnected
Oct 11 11:37:17 ReadyNAS upsmon[2591]: Poll UPS [UPS@localhost] failed - Driver not connected
Oct 11 11:37:27 ReadyNAS upsmon[2591]: Set username on [UPS@localhost] failed: Server disconnected
Oct 11 11:37:32 ReadyNAS upsmon[2591]: Poll UPS [UPS@localhost] failed - Driver not connected
Oct 11 11:37:42 ReadyNAS upsmon[2591]: Set username on [UPS@localhost] failed: Server disconnected
Oct 11 11:37:47 ReadyNAS upsmon[2591]: Poll UPS [UPS@localhost] failed - Driver not connected
Oct 11 11:37:57 ReadyNAS upsmon[2591]: Set username on [UPS@localhost] failed: Server disconnected
Oct 11 11:38:02 ReadyNAS upsmon[2591]: Poll UPS [UPS@localhost] failed - Driver not connected
Oct 11 11:38:12 ReadyNAS upsmon[2591]: Set username on [UPS@localhost] failed: Server disconnected

● nut-driver.service - Network UPS Tools - power device driver controller
   Loaded: loaded (/lib/systemd/system/nut-driver.service; static; vendor preset: disabled)
   Active: active (running) since Mon 2016-10-10 12:06:00 PDT; 23h ago
  Process: 2573 ExecStart=/sbin/upsdrvctl start (code=exited, status=0/SUCCESS)
 Main PID: 2584 (usbhid-ups)
   CGroup: /system.slice/nut-driver.service
           └─2584 /lib/nut/usbhid-ups -a UPS

Oct 10 12:06:00 ReadyNAS systemd[1]: Starting Network UPS Tools - power device driver controller...
Oct 10 12:06:00 ReadyNAS upsdrvctl[2573]: Using subdriver: CyberPower HID 0.4
Oct 10 12:06:00 ReadyNAS upsdrvctl[2573]: Network UPS Tools - Generic HID driver 0.41 (2.7.4)
Oct 10 12:06:00 ReadyNAS upsdrvctl[2573]: USB communication driver 0.33
Oct 10 12:06:00 ReadyNAS upsdrvctl[2573]: Network UPS Tools - UPS driver controller 2.7.4
Oct 10 12:06:00 ReadyNAS systemd[1]: Started Network UPS Tools - power device driver controller.
Oct 10 12:06:00 ReadyNAS usbhid-ups[2584]: Startup successful

One weird thing I saw, was when restarting the drivers that the IPv6 stuff is acting weird.

Oct 11 11:39:38 ReadyNAS upsd[2586]: write() failed for ::1: Broken pipe
Oct 11 11:39:38 ReadyNAS upsd[2586]: write() failed for ::1: Broken pipe
Oct 11 11:39:38 ReadyNAS upsd[2586]: write() failed for ::1: Broken pipe
Oct 11 11:39:38 ReadyNAS upsd[2586]: write() failed for ::1: Broken pipe

And when restart completed the monuser account logs in by default using ipv6

Oct 11 11:46:32 ReadyNAS upsdrvctl[9404]: Using subdriver: CyberPower HID 0.4
Oct 11 11:46:32 ReadyNAS upsdrvctl[9404]: Network UPS Tools - Generic HID driver 0.41 (2.7.4)
Oct 11 11:46:32 ReadyNAS upsdrvctl[9404]: USB communication driver 0.33
Oct 11 11:46:32 ReadyNAS upsdrvctl[9404]: Network UPS Tools - UPS driver controller 2.7.4
Oct 11 11:46:32 ReadyNAS upsd[9416]: listening on 0.0.0.0 port 3493
Oct 11 11:46:32 ReadyNAS upsd[9416]: listening on ::1 port 3493
Oct 11 11:46:32 ReadyNAS upsd[9416]: not listening on 127.0.0.1 port 3493
Oct 11 11:46:32 ReadyNAS upsd[9416]: Connected to UPS [UPS]: usbhid-ups-UPS
Oct 11 11:46:32 ReadyNAS upsd[9417]: Startup successful
Oct 11 11:46:33 ReadyNAS upsd[9417]: User monuser@::1 logged into UPS [UPS]

Hope this isnt too much spam, but what I could gather from my knowledge..

Lets hope we can figure out why hardware wise its getting stale data.

FYI I have IPv6 disabled on my network using just eth0

I also have changed UPSD.conf to incorporate MAXAGE 30 to allow the driver more time to process the stale data before disconnecting.

I'll keep you posted on the outcome

ShoGinn · ‎2016-10-11

Modification of the UPSD.conf to modify the MAXAGE to 30 did not fix the problem.

Awaiting further help.

bobaloca · ‎2016-10-12

Just to chime in, I recently upgraded my old Pro 6 to OS6.6, and have inconsistent readings from my Cyberpower UPS. It was green at first, but now is a warning state (yellow).

bobaloca · ‎2016-10-13

p.s system.log shows something a bit different from OP:

Oct 13 07:51:55 ReadyNAS-Pro6 upsmon[3723]: Poll UPS [UPS@localhost] failed - Driver not connected
Oct 13 07:52:05 ReadyNAS-Pro6 upsmon[3723]: Set username on [UPS@localhost] failed: Server disconnected
Oct 13 07:52:10 ReadyNAS-Pro6 upsmon[3723]: Poll UPS [UPS@localhost] failed - Driver not connected
Oct 13 07:52:20 ReadyNAS-Pro6 upsmon[3723]: Set username on [UPS@localhost] failed: Server disconnected
Oct 13 07:52:25 ReadyNAS-Pro6 upsmon[3723]: Poll UPS [UPS@localhost] failed - Driver not connected