[Nut-upsuser] upssched problem on NUT 2.4.3

Arnaud Quette aquette.dev at gmail.com
Tue Sep 13 08:24:11 UTC 2011 

Hi,

2011/9/12 Dupdup Sys <dupdupsystems at gmail.com>

>
>
> Hi,
> I would like firstly be more precise: The ups is an EATON Evolution 1550. I
> tried two different servers with debian amd64. On the first one I had
> several usb issues such as disconnections occuring sometimes and that maked
> ups monitoring impossible on nut impossible.
> On the new server (dell sc1430, running on a xeon quadcore), I still have
> usb issues, however it only occurs when the power came back.
>

thanks for the details.
are there any other USB devices on the same bus than the UPS?


> *upssched.conf:*
>
> CMDSCRIPT /etc/nut/upsalert
>
> PIPEFN /var/run/nut/upssched/upssched.pipe
> LOCKFN /var/run/nut/upssched/upssched.lock
>
> AT ONBATT * START-TIMER timerondubatterie 600
> AT ONLINE * CANCEL-TIMER timerondubatterie
>
>
> *ups.conf:*
> [EATON]
> driver=usbhid-ups
> port=auto
>
>
>
>
> *A copy of /var/log/daemon.log before a power loss:*
>
>
> Sep  2 17:47:49 debiandell usbhid-ups[1770]: Startup successful****
>
> Sep  2 17:47:49 debiandell upsd[1771]: listening on 127.0.0.1 port 3493***
> *
>
> Sep  2 17:47:49 debiandell upsd[1771]: Connected to UPS [EATON]:
> usbhid-ups-EATON****
>
> Sep  2 17:47:49 debiandell upsd[1772]: Startup successful****
>
> Sep  2 17:47:49 debiandell upsmon[1774]: Startup successful****
>
> Sep  2 17:47:49 debiandell upsd[1772]: User onduuser at 127.0.0.1 logged into
> UPS [EATON]
>
>
> *daemon.log showing a power loss:*
>
> Sep  2 17:54:19 debiandell upsmon[1776]: UPS EATON at localhost on battery***
> *
>
> Sep  2 17:54:19 debiandell upssched[1786]: New timer: onbatt (600 seconds)
> ****
>
> Sep  2 17:55:04 debiandell usbhid-ups[1770]: libusb_get_interrupt: error
> submitting URB: No such device****
>
> Sep  2 17:55:04 debiandell usbhid-ups[1770]: libusb_get_report: error
> sending control message: No such device****
>
> Sep  2 17:55:18 debiandell upsd[1772]: Data for UPS [EATON] is stale -
> check driver****
>
> Sep  2 17:55:19 debiandell upsmon[1776]: Poll UPS [EATON at localhost] failed
> - Data stale****
>
> Sep  2 17:55:19 debiandell upsmon[1776]: Communications with UPS
> EATON at localhost lost****
>
> Sep  2 17:55:24 debiandell upsmon[1776]: Poll UPS [EATON at localhost] failed
> - Data stale****
>
> Sep  2 17:55:28 debiandell upsd[1772]: UPS [EATON] data is no longer stale
> ****
>
> Sep  2 17:55:29 debiandell upsmon[1776]: Communications with UPS
> EATON at localhost established****
>
> Sep  2 17:55:29 debiandell upsmon[1776]: UPS EATON at localhost on line power
> ****
>
> ****
>
> *syslog:*
>
>
>
> Sep  2 17:54:19 debiandell upsmon[1776]: UPS EATON at localhost on battery***
> *
>
> Sep  2 17:54:19 debiandell upssched[1786]: New timer: onbatt (600 seconds)
> ****
>
> *Sep  2 17:55:04 debiandell kernel: [  590.640043] hub 4-0:1.0: port 2
> disabled by hub (EMI?), re-enabling...*****
>
> *Sep  2 17:55:04 debiandell kernel: [  590.640144] usb 4-2: USB
> disconnect, address 4*****
>
> Sep  2 17:55:04 debiandell usbhid-ups[1770]: libusb_get_interrupt: error
> submitting URB: No such device****
>
> Sep  2 17:55:04 debiandell usbhid-ups[1770]: libusb_get_report: error
> sending control message: No such device****
>
> Sep  2 17:55:04 debiandell kernel: [  590.880772] usb 4-2: new low speed
> USB device using uhci_hcd and address 5****
>
> Sep  2 17:55:05 debiandell kernel: [  591.501730] usb 4-2: New USB device
> found, idVendor=0463, idProduct=ffff****
>
> Sep  2 17:55:05 debiandell kernel: [  591.501735] usb 4-2: New USB device
> strings: Mfr=1, Product=2, SerialNumber=3****
>
> Sep  2 17:55:05 debiandell kernel: [  591.501738] usb 4-2: Product:
> Evolution****
>
> Sep  2 17:55:05 debiandell kernel: [  591.501741] usb 4-2: Manufacturer:
> EATON****
>
> Sep  2 17:55:05 debiandell kernel: [  591.501743] usb 4-2: SerialNumber:
> ARDM0204T****
>
> Sep  2 17:55:05 debiandell kernel: [  591.501873] usb 4-2: configuration
> #1 chosen from 1 choice****
>
> Sep  2 17:55:05 debiandell kernel: [  591.690745] generic-usb: probe of
> 0003:0463:FFFF.0004 failed with error -71****
>
> Sep  2 17:55:05 debiandell kernel: [  591.880039] hub 4-0:1.0: port 2
> disabled by hub (EMI?), re-enabling...****
>
> Sep  2 17:55:05 debiandell kernel: [  591.880115] usb 4-2: USB disconnect,
> address 5****
>
> Sep  2 17:55:05 debiandell kernel: [  592.120009] usb 4-2: new low speed
> USB device using uhci_hcd and address 6****
>
> Sep  2 17:55:11 debiandell kernel: [  597.236010] usb 4-2: device
> descriptor read/64, error -32****
>
> Sep  2 17:55:11 debiandell kernel: [  597.460009] usb 4-2: device
> descriptor read/64, error -32****
>
> Sep  2 17:55:11 debiandell kernel: [  597.676017] usb 4-2: new low speed
> USB device using uhci_hcd and address 7****
>
> Sep  2 17:55:11 debiandell kernel: [  597.796009] usb 4-2: device
> descriptor read/64, error -32****
>
> Sep  2 17:55:12 debiandell kernel: [  598.520581] usb 4-2: New USB device
> found, idVendor=0463, idProduct=ffff****
>
> Sep  2 17:55:12 debiandell kernel: [  598.520585] usb 4-2: New USB device
> strings: Mfr=1, Product=2, SerialNumber=3****
>
> Sep  2 17:55:12 debiandell kernel: [  598.520588] usb 4-2: Product:
> Evolution****
>
> Sep  2 17:55:12 debiandell kernel: [  598.520590] usb 4-2: Manufacturer:
> EATON****
>
> Sep  2 17:55:12 debiandell kernel: [  598.520593] usb 4-2: SerialNumber:
> ARDM0204T****
>
> Sep  2 17:55:12 debiandell kernel: [  598.520694] usb 4-2: configuration
> #1 chosen from 1 choice****
>
> Sep  2 17:55:18 debiandell upsd[1772]: Data for UPS [EATON] is stale -
> check driver****
>
> Sep  2 17:55:19 debiandell upsmon[1776]: Poll UPS [EATON at localhost] failed
> - Data stale****
>
> Sep  2 17:55:19 debiandell upsmon[1776]: Communications with UPS
> EATON at localhost lost****
>
> Sep  2 17:55:24 debiandell upsmon[1776]: Poll UPS [EATON at localhost] failed
> - Data stale****
>
> Sep  2 17:55:25 debiandell kernel: [  611.737424]
> /build/buildd-linux-2.6_2.6.32-35-amd64-aZSlKL/linux-2.6-2.6.32/debian/build/source_amd64_none/drivers/hid/usbhid/hid-core.c:
> usb_submit_urb(ctrl) failed****
>
> Sep  2 17:55:25 debiandell kernel: [  611.737551] generic-usb
> 0003:0463:FFFF.0005: timeout initializing reports****
>
> Sep  2 17:55:25 debiandell kernel: [  611.737681] generic-usb
> 0003:0463:FFFF.0005: hiddev0,hidraw1: USB HID v1.10 Device [EATON Evolution]
> on usb-0000:00:1d.2-2/input0****
>
> Sep  2 17:55:28 debiandell upsd[1772]: UPS [EATON] data is no longer stale
> ****
>
> Sep  2 17:55:29 debiandell upsmon[1776]: Communications with UPS
> EATON at localhost established****
>
> Sep  2 17:55:29 debiandell upsmon[1776]: UPS EATON at localhost on line power
> ****
>
>
there, we should have the timer cleared!
do you have any further messages related to upssched?

I have to check more in depth, but upssched has probably cleared the
connection with the UPS since it was broken. It then doesn't try to reopen
it, which leaves a hole for your kind of issue.
if it's the case, you should have "Tried to delete a bogus state connection"
in your syslog.
(can you please check this one?)

*lsusb:*
>
> Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub****
>
> Bus 004 Device 002: ID 0463:ffff MGE UPS Systems UPS****
>
> Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub****
>
> Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub****
>
> Bus 002 Device 002: ID 413c:2003 Dell Computer Corp. Keyboard****
>
> Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub****
>
> Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub****
>
>
> Yet this makes me puzzled, for the following reasons: On windows 7, I do
> not have any message or errors showing a USB disconnection. Then, I was
> using a MGE Ellipse 1500, with the same driver, on the former server, and it
> worked perfectly for years. On the one side I feel like the problem is on
> the ups, but windows and the personnal solution pac software given are
> working.
>

it's hard to tell: this may come from the UPS, server (USB hubs), kernel or
a conjunction of several of these.

you may try with a low speed hub (ie, not an ehci nor in ehci mode), or try
other root hub to see if there are differences.

cheers,
Arnaud
-- 
Linux / Unix Expert R&D - Eaton - http://powerquality.eaton.com
Network UPS Tools (NUT) Project Leader - http://www.networkupstools.org/
Debian Developer - http://www.debian.org
Free Software Developer - http://arnaud.quette.free.fr/

Le 12/09/2011 13:31, Arnaud Quette a écrit :
>
> Hi
>
> 2011/9/10 Dupdup Sys <dupdupsystems at gmail.com>
>
>>  Thanks for you answer.
>> When the UPS comes offline upssched is now lauching the timer. However
>> when the UPS gets online the timer does not stop.
>> Yet I think it is due to another problem: when it comes online my UPS gets
>> disconnected for a very short time, and it takes a few seconds to have it
>> back on usb and with an online status on nut. I hope to receive pieces of
>> advise from EATON regarding this issue. This might be a physical problem
>> coming from my ups.
>> Best Regards.
>>
>
> I'd like to see your upssched.conf, along with an excerpt of your
> /var/log/syslog on the "ups" pattern please.
> as for the disconnection, it may be the device or the kernel.
> you should also have a look at the syslog for this, and send me anything
> you've found, related to that (grep on "connect")
>
> cheers,
> Arnaud
> --
> Linux / Unix Expert R&D - Eaton - http://powerquality.eaton.com
> Network UPS Tools (NUT) Project Leader - http://www.networkupstools.org/
> Debian Developer - http://www.debian.org
> Free Software Developer - http://arnaud.quette.free.fr/
>
>   Le 08/09/2011 17:27, Arnaud Quette a écrit :
>>
>> Hi,
>>
>> 2011/9/1 Dupdup Sys <dupdupsystems at gmail.com>
>>
>>> Hello,
>>> I am currently building a new server using debian amd64. Therefore I need
>>> to use my UPS EATON Evolution 1550 on it, using usbhid-ups driver.
>>> I installed nut with apt (version 2.4.3-1.1squeeze1) on debian 2.6.32-5
>>> amd64.
>>>
>>> I can currently use nut with the drivers, upsc and upsmon: my UPS is
>>> detected and works. Actually everything works except upssched: I can shut
>>> down the server using upsmon -c fsd. I didn't try yet but I think the
>>> automatic shutdown  would work either, the server should stop when the ups
>>> battery goes too low.
>>>
>>> However I definetely can't make upssched running, which is such a big
>>> deal because I would like to use the timer functions to have a shutdown
>>> after ten minutes without electricity.
>>> I created in /var/run/nut an upssched folder to contain the upssched
>>> files, made chgrp nut.nut and chmod 755. My upsmon.conf contains the
>>> NOTIFYCMD /sbin/upssched.
>>>
>>> Here comes the issue: I can't find any lead of upssched in
>>> /var/log/daemon.log. While usbhid-ups, upsd and upsmon have their entries in
>>> the logfile and are working, I can't find anything about upssched in the
>>> logs. Thereby I do think that upssched is inactive, but I am still wondering
>>> if the problem is not in upsmon: I tried several permissions, tried to use
>>> an other script in upsmon.conf, but didn't manage to have it working.
>>>
>>> Do you have any idea on how this could be solve ?
>>> Best Regards.
>>>
>>
>> upssched is only active when needed, ie when upsmon fires it because of
>> execution triggers.
>>
>> so you have to meet these conditions, ie switching on battery, ..., as you
>> have defined in upsmon.conf or as done by default.
>>
>> note that /var/run/nut is created automatically when calling the nut init
>> script on Debian.
>>
>> cheers,
>> Arnaud
>> --
>> Linux / Unix Expert R&D - Eaton - http://powerquality.eaton.com
>> Network UPS Tools (NUT) Project Leader - http://www.networkupstools.org/
>> Debian Developer - http://www.debian.org
>> Free Software Developer - http://arnaud.quette.free.fr/
>>
>>
>>
>
>
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.alioth.debian.org/pipermail/nut-upsuser/attachments/20110913/b3880754/attachment-0001.html>

More information about the Nut-upsuser mailing list