UPS - Data for UPS [Eaton5S700i] is stale - check driver

[Spencer Skinner]

Hey guys

Got a new UPS yesterday, all set up seemed to work when i did my tests and it powered the server and then shut it down correctly.

But i am getting some very annoying messages come up and im also getting allot of COMMBAD emails.

I have also brought this up in one of my other posts that i made asking about what UPS to buy, but i felt it was appropriate to make a new thread for it seeing as its a fairly big issue in itself.

UPS - Eaton 5S700i

Here is the error thats getting chugged out -

Code:

Feb  1 18:48:15 freenas notifier: Starting nut_upslog.
Feb  1 19:39:26 freenas upsd[6342]: Data for UPS [Eaton5S700i] is stale - check driver
Feb  1 19:39:27 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  1 19:39:29 freenas ugen0.2: <EATON> at usbus0
Feb  1 19:39:29 freenas upsmon[6367]: Poll UPS [Eaton5S700i] failed - Data stale
Feb  1 19:39:29 freenas upsmon[6367]: Communications with UPS Eaton5S700i lost
Feb  1 19:39:32 freenas upsd[6342]: UPS [Eaton5S700i] data is no longer stale
Feb  1 19:39:34 freenas upsmon[6367]: Communications with UPS Eaton5S700i established
Feb  1 19:44:28 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  1 19:44:29 freenas upsd[6342]: Data for UPS [Eaton5S700i] is stale - check driver
Feb  1 19:44:30 freenas upsmon[6367]: Poll UPS [Eaton5S700i] failed - Data stale
Feb  1 19:44:30 freenas upsmon[6367]: Communications with UPS Eaton5S700i lost
Feb  1 19:44:32 freenas ugen0.2: <EATON> at usbus0
Feb  1 19:44:35 freenas upsd[6342]: UPS [Eaton5S700i] data is no longer stale
Feb  1 19:44:35 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  1 19:44:35 freenas upsmon[6367]: Communications with UPS Eaton5S700i established
Feb  1 19:44:39 freenas ugen0.2: <EATON> at usbus0
Feb  1 20:01:35 freenas upsd[6342]: Data for UPS [Eaton5S700i] is stale - check driver
Feb  1 20:01:36 freenas upsmon[6367]: Poll UPS [Eaton5S700i] failed - Data stale
Feb  1 20:01:36 freenas upsmon[6367]: Communications with UPS Eaton5S700i lost
Feb  1 20:01:36 freenas upsd[6342]: UPS [Eaton5S700i] data is no longer stale
Feb  1 20:01:41 freenas upsmon[6367]: Communications with UPS Eaton5S700i established

Here are the setting i have enabled -
View attachment 15729 View attachment 15730

Any ideas as to what this could be, cant be normal surely?


Thanks
Spencer Skinner

EDIT - Tried changing the usb interface to ugen0.2 here is what i get -

Code:

Feb  1 20:08:14 freenas notifier: Starting nut_upslog.
Feb  1 20:12:01 freenas upsd[11156]: Data for UPS [Eaton5S700i] is stale - check driver
Feb  1 20:12:01 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  1 20:12:03 freenas ugen0.2: <EATON> at usbus0
Feb  1 20:12:05 freenas upsmon[11181]: Poll UPS [Eaton5S700i] failed - Data stale
Feb  1 20:12:05 freenas upsmon[11181]: Communications with UPS Eaton5S700i lost
Feb  1 20:12:06 freenas upsd[11156]: UPS [Eaton5S700i] data is no longer stale
Feb  1 20:12:10 freenas upsmon[11181]: Communications with UPS Eaton5S700i established
Feb  1 20:13:17 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  1 20:13:17 freenas upsd[11156]: Data for UPS [Eaton5S700i] is stale - check driver
Feb  1 20:13:18 freenas usb_alloc_device: set address 2 failed (USB_ERR_IOERROR, ignored)
Feb  1 20:13:18 freenas usbd_setup_device_desc: getting device descriptor at addr 2 failed, USB_ERR_IOERROR
Feb  1 20:13:18 freenas usbd_req_re_enumerate: addr=2, set address failed! (USB_ERR_IOERROR, ignored)
Feb  1 20:13:18 freenas usbd_setup_device_desc: getting device descriptor at addr 2 failed, USB_ERR_IOERROR
Feb  1 20:13:19 freenas usbd_req_re_enumerate: addr=2, set address failed! (USB_ERR_IOERROR, ignored)
Feb  1 20:13:19 freenas usbd_setup_device_desc: getting device descriptor at addr 2 failed, USB_ERR_IOERROR
Feb  1 20:13:20 freenas ugen0.2: <EATON> at usbus0
Feb  1 20:13:21 freenas upsmon[11181]: Poll UPS [Eaton5S700i] failed - Data stale
Feb  1 20:13:21 freenas upsmon[11181]: Communications with UPS Eaton5S700i lost
Feb  1 20:13:22 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  1 20:13:23 freenas ugen0.2: <EATON> at usbus0
Feb  1 20:13:26 freenas upsmon[11181]: Poll UPS [Eaton5S700i] failed - Data stale
Feb  1 20:13:26 freenas upsd[11156]: UPS [Eaton5S700i] data is no longer stale
Feb  1 20:13:31 freenas upsmon[11181]: Communications with UPS Eaton5S700i established

 

[Kevin Horton]

I had similar problems with my APC Back-up Pro BR1000G UPS, using the usbhid-ups driver. A search on the forum found numerous other posts about this issue, and a solution (please note that this thread is discussing an earlier FreeNAS version, where there was no means in the GUI to add parameters to upsd.conf, thus the discussion about using the CLI to add that parametre).

I solved my problem by putting MAXAGE 25 in the "Auxiliary parameters (upsd.conf)" field in the UPS Settings in Services.

 

[Spencer Skinner]

I

I had similar problems with my APC Back-up Pro BR1000G UPS, using the usbhid-ups driver. A search on the forum found numerous other posts about this issue, and a solution (please note that this thread is discussing an earlier FreeNAS version, where there was no means in the GUI to add parameters to upsd.conf, thus the discussion about using the CLI to add that parametre).

I solved my problem by putting MAXAGE 25 in the "Auxiliary parameters (upsd.conf)" field in the UPS Settings in Services.

I had seen this post to be fair i was just unsure as to what they were refering to when they were adding parameters to the UPS service. Now you mention it being a different version it clicked.

Thats my bad lack of thorough reading, I appreciate the help.

Ill test this for the next few hours and let you know if it works.

Thanks
Spencer Skinner

 

[Spencer Skinner]

I had similar problems with my APC Back-up Pro BR1000G UPS, using the usbhid-ups driver. A search on the forum found numerous other posts about this issue, and a solution (please note that this thread is discussing an earlier FreeNAS version, where there was no means in the GUI to add parameters to upsd.conf, thus the discussion about using the CLI to add that parametre).

I solved my problem by putting MAXAGE 25 in the "Auxiliary parameters (upsd.conf)" field in the UPS Settings in Services.

The issue seems to have come back again, still getting the COMMBAD emails and the data stale errors?

Any ideas?

 

[Ericloewe]

Haven't had any of these problems since 9.10 was released. The improved USB stack seems to have solved those.

 

[Kevin Horton]

The issue seems to have come back again, still getting the COMMBAD emails and the data stale errors?

Any ideas?

Please confirm that after adding MAXAGE=25, you stopped and restarted the UPS service to force it to load the new parametre.

 

[Spencer Skinner]

Please confirm that after adding MAXAGE=25, you stopped and restarted the UPS service to force it to load the new parametre.

Can confirm yeh, i have restarted the UPS service and i am still experiencing the issues

 

[Kevin Horton]

The thread I quoted earlier points to the NUT docs, which suggest that MAXAGE=30 may be required, or that DEADTIME may need to be increased. I have no idea what DEADTIME value would be required - the small log snippet suggests that something larger than 5 would be needed. I suggest you start with a large value, and reduce in increments if it stops the messages, until you figure out the minimum value that solves the problem.

 

[Spencer Skinner]

The thread I quoted earlier points to the NUT docs, which suggest that MAXAGE=30 may be required, or that DEADTIME may need to be increased. I have no idea what DEADTIME value would be required - the small log snippet suggests that something larger than 5 would be needed. I suggest you start with a large value, and reduce in increments if it stops the messages, until you figure out the minimum value that solves the problem.

When you say a large value should i be looking at starting with like 50? or even bigger than that? Ive also upped MAXAGE to 30

 

[Kevin Horton]

When you say a large value should i be looking at starting with like 50? or even bigger than that? Ive also upped MAXAGE to 30

Try a DEADTIME value of 50 to see if this parameter is relevant to your problem. But, that will add a time delay between the AC power fails and when FreeNAS is aware of this, so don't leave a large value set any longer than needed for testing.

 

[joeschmuck]

First of all, if you unplug the UPS does your system, shutdown as expected? Hopefully it does.

Next I'd set the MAXAGE=50 and see if the messages go away and I'd increase it again all the way up to 120 for testing purposes alone. The initial goal is to try and get rid of the stale reports. If you can do that then you can drop the value a bit and over a period of a day you may be able to dial in the proper value, then unplug the UPS again and ensure FreeNAS shuts down as expected.

As for DEADTIME, I would refrain from using it if possible however you might need it.

Just curious, what does the output of "upsc ups" output? You might need to change "ups" to the name in "identifier" field.

 

[Spencer Skinner]

First of all, if you unplug the UPS does your system, shutdown as expected? Hopefully it does.

Next I'd set the MAXAGE=50 and see if the messages go away and I'd increase it again all the way up to 120 for testing purposes alone. The initial goal is to try and get rid of the stale reports. If you can do that then you can drop the value a bit and over a period of a day you may be able to dial in the proper value, then unplug the UPS again and ensure FreeNAS shuts down as expected.

As for DEADTIME, I would refrain from using it if possible however you might need it.

Just curious, what does the output of "upsc ups" output? You might need to change "ups" to the name in "identifier" field.

Ive removed the DEADTIME = 50 now seeing as it did not do anything and ive increased MAXAGE to 50

As for upsc [IDENTIFIER]

Code:

[root@freenas ~]# ups Eaton5S700i																								   
bash: ups: command not found																										
[root@freenas ~]# upsc Eaton5S700i																								 
battery.charge: 95																												 
battery.charge.low: 20																											 
battery.runtime: 1558																											   
device.mfr: EATON																												   
device.model: 5S 700																												
device.type: ups																													
driver.name: usbhid-ups																											 
driver.parameter.pollfreq: 30																									   
driver.parameter.pollinterval: 2																									
driver.parameter.port: /dev/ugen0.4																								 
driver.parameter.synchronous: no																									
driver.version: 2.7.3																											   
driver.version.data: MGE HID 1.38																								   
driver.version.internal: 0.39																									   
input.frequency: 50.5																											   
input.voltage: 240.0																												
outlet.1.desc: PowerShare Outlet 1																								 
outlet.1.id: 2																													 
outlet.1.status: on																												 
outlet.desc: Main Outlet																											
outlet.id: 1																														
output.frequency: 50.0																											 
output.voltage: 230.0																											   
ups.beeper.status: disabled																										 
ups.delay.shutdown: 20																											 
ups.delay.start: 30																												 
ups.firmware: 01.10.0016																											
ups.load: 17																														
ups.mfr: EATON																													 
ups.model: 5S 700																												   
ups.power: 119																													 
ups.power.nominal: 700																											 
ups.productid: ffff																												 
ups.realpower: 119																												 
ups.status: OL																													 
ups.timer.shutdown: -1																											 
ups.timer.start: -1																												 
ups.vendorid: 0463																												 
[root@freenas ~]#

And yes it does work when i turn off the power it shuts down as it should

 

[joeschmuck]

Well nothing popped out in the ups data but I'd just make MAXAGE some crazy value and if the problem goes away, then start reducing the value until the problem comes back and then of course fine tune it until the problem goes away.

I have not looked but does the Eaton 5S have a firmware upgrade? Maybe you can't change it but it's worth looking into. I like to think outside the box from time to time. Also ensure you do a Google Search for your model UPS, FreeBSD, NUT, and the Stale messages. Remember that FreeNAS 9.10.x is built on FreeBSD 10 so you might find help in a FreeBSD forum, that is how I do it.

 

[Spencer Skinner]

Well nothing popped out in the ups data but I'd just make MAXAGE some crazy value and if the problem goes away, then start reducing the value until the problem comes back and then of course fine tune it until the problem goes away.

I have not looked but does the Eaton 5S have a firmware upgrade? Maybe you can't change it but it's worth looking into. I like to think outside the box from time to time. Also ensure you do a Google Search for your model UPS, FreeBSD, NUT, and the Stale messages. Remember that FreeNAS 9.10.x is built on FreeBSD 10 so you might find help in a FreeBSD forum, that is how I do it.

Ive set the MAXAGE to 120 and still am not getting any progress with this, got loads of emails overnight. Doesnt seem to be anything online with the Eaton 5S and FreeBSD or at least not that ive seen so far. And ill give the drivers a try later on when im home

Thanks
Spencer Skinner

 

[joeschmuck]

Also try other drivers, don't stick just to ones labeled Eaton. Use the upsc comand to ensure you have communications and then see if the problem clears.

 

[Spencer Skinner]

Ive set the MAXAGE to 120 and still am not getting any progress with this, got loads of emails overnight. Doesnt seem to be anything online with the Eaton 5S and FreeBSD or at least not that ive seen so far. And ill give the drivers a try later on when im home

Thanks
Spencer Skinner

Yeh have tried a few other variations on the FreeNAS UPS drivers, also checked for firmware updates for the UPS and got nothing, ill keep trying drivers, should i be trying them with the MAXAGE 120 Parameters too?

Ive also noticed that the UPS seems to swap between /dev/ugen0.2 and /dev/ugen0.4

 

[joeschmuck]

Ive also noticed that the UPS seems to swap between /dev/ugen0.2 and /dev/ugen0.4

This is okay. If you plug in the USB port after FreeNAS is running and you have the footer messages selected, you will see the port that the UPS is using. If you move the USB port then you will see this value change, and sometimes it will just change based on how the system boots up.

should i be trying them with the MAXAGE 120 Parameters too?

The value is high but I see nothing bad using it, but you could drop it to 60 if you desire. Hopefully you will find the correct settings to make this work for you. And I wish I had told you that you should have purchased an APC UPS but I had no idea the Eaton would give you such trouble.

Just curious, are you plugging into a motherboard USB port directly? Also, a USB 2.x version (not blue in color), and have you tried a blue (USB 3.x) port? I don't think this is a port issue but it's worth a try.

 

[Spencer Skinner]

This is okay. If you plug in the USB port after FreeNAS is running and you have the footer messages selected, you will see the port that the UPS is using. If you move the USB port then you will see this value change, and sometimes it will just change based on how the system boots up.


The value is high but I see nothing bad using it, but you could drop it to 60 if you desire. Hopefully you will find the correct settings to make this work for you. And I wish I had told you that you should have purchased an APC UPS but I had no idea the Eaton would give you such trouble.

Just curious, are you plugging into a motherboard USB port directly? Also, a USB 2.x version (not blue in color), and have you tried a blue (USB 3.x) port? I don't think this is a port issue but it's worth a try.

Plugged into a usb 2.0 Port have also tried a 3.0 port nothing changed. Ive swapped the MAXAGE down to 60. Ive got no idea why this is happening ahaha. My FreeNAS email folder is looking populated to say the least ahaha

EDIT -
I also now get loads of these messages in bursts

Code:

Feb  4 23:03:49 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  4 23:03:54 freenas ugen0.2: <EATON> at usbus0
Feb  4 23:04:00 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  4 23:04:02 freenas ugen0.2: <EATON> at usbus0

EDIT 2 -

Here is a bit more of what i now get

Code:

Feb  4 23:03:49 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  4 23:03:54 freenas ugen0.2: <EATON> at usbus0
Feb  4 23:04:00 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  4 23:04:02 freenas ugen0.2: <EATON> at usbus0
Feb  4 23:05:46 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  4 23:05:46 freenas upsd[10163]: Data for UPS [ups] is stale - check driver
Feb  4 23:05:50 freenas upsmon[10180]: Poll UPS [ups] failed - Data stale
Feb  4 23:05:50 freenas upsmon[10180]: Communications with UPS ups lost
Feb  4 23:05:51 freenas ugen0.2: <EATON> at usbus0
Feb  4 23:05:55 freenas upsmon[10180]: Poll UPS [ups] failed - Data stale
Feb  4 23:05:57 freenas upsd[10163]: UPS [ups] data is no longer stale
Feb  4 23:05:57 freenas ugen0.2: <EATON> at usbus0 (disconnected)
Feb  4 23:05:58 freenas usb_alloc_device: set address 2 failed (USB_ERR_IOERROR, ignored)
Feb  4 23:05:58 freenas usbd_setup_device_desc: getting device descriptor at addr 2 failed, USB_ERR_IOERROR
Feb  4 23:05:58 freenas usbd_req_re_enumerate: addr=2, set address failed! (USB_ERR_IOERROR, ignored)
Feb  4 23:05:59 freenas usbd_setup_device_desc: getting device descriptor at addr 2 failed, USB_ERR_IOERROR
Feb  4 23:05:59 freenas usbd_req_re_enumerate: addr=2, set address failed! (USB_ERR_IOERROR, ignored)
Feb  4 23:05:59 freenas usbd_setup_device_desc: getting device descriptor at addr 2 failed, USB_ERR_IOERROR
Feb  4 23:05:59 freenas usbd_req_re_enumerate: addr=2, set address failed! (USB_ERR_IOERROR, ignored)
Feb  4 23:05:59 freenas usbd_setup_device_desc: getting device descriptor at addr 2 failed, USB_ERR_IOERROR
Feb  4 23:06:00 freenas usbd_req_re_enumerate: addr=2, set address failed! (USB_ERR_IOERROR, ignored)
Feb  4 23:06:00 freenas upsd[10163]: Data for UPS [ups] is stale - check driver
Feb  4 23:06:00 freenas usbd_setup_device_desc: getting device descriptor at addr 2 failed, USB_ERR_IOERROR
Feb  4 23:06:00 freenas ugen0.2: <Unknown> at usbus0 (disconnected)
Feb  4 23:06:00 freenas uhub_reattach_port: could not allocate new device
Feb  4 23:06:00 freenas upsmon[10180]: Poll UPS [ups] failed - Data stale
Feb  4 23:06:02 freenas ugen0.2: <EATON> at usbus0
Feb  4 23:06:05 freenas upsmon[10180]: Poll UPS [ups] failed - Data stale
Feb  4 23:06:08 freenas upsd[10163]: UPS [ups] data is no longer stale
Feb  4 23:06:10 freenas upsmon[10180]: Communications with UPS ups established

 

[Mr_N]

that looks like either your cable or the port on your MB or in your UPS is faulty , if its unable to maintain a stable USB connection thats probably causing the other errors...

the only time you should see connection/disconnections is at bootup and if you physically unplug the cable...

 

[Spencer Skinner]

that looks like either your cable or the port on your MB or in your UPS is faulty , if its unable to maintain a stable USB connection thats probably causing the other errors...

the only time you should see connection/disconnections is at bootup and if you physically unplug the cable...

I think your right because ive just hooked it up to my laptop and im getting similar errors via there application "UPS Companion". Looooks like an RMA to me ahaha, Bugger