[Nut-upsdev] [Nut-upsuser] Getting 'Data stale' error with bcmxcp_usb for a PowerWare 5115 on OSX

Wed Mar 10 08:56:37 UTC 2010

Good evening,

Sorry for taking a while to get back to this; I've been away for 
a couple of days.

On 7/03/10 at 7:57 AM -0500, Charles Lepple <clepple at gmail.com> wrote:

>> Anything else I can test?
>
>How about putting a few upslogx() calls into the read loop mentioned
>above (bcmxcp_usb.c, ~line 150). That would confirm that we are
>looking in the right place, and also could yield some information such
>as the return value of usb_interrupt_read().
>
>If that is causing problems, I have a mostly untested patch here which
>might restore some of the logging, but to a separate file so you don't
>spam your syslog files.
>
>I will look into what is necessary to reconnect the driver (which I
>suspect is how my UPSes eventually start working on OS X).

I reproduced the debug lines with calls to upslogx, plus added a 
few others. The output from the command line follows, and then 
see further down for output written to console log:

NUT $ sudo /usr/local/ups/bin/upsdrvctl start
Network UPS Tools - UPS driver controller 2.4.3-2392M
Network UPS Tools - BCMXCP UPS driver 0.23 (2.4.3-2392M)
USB communication subdriver 0.18
entering get_answer(31)
About to start loop ...
Let's read some data; length: 1, bytes_read: 0
We've got something to read ...
usb_interrupt_read is 166
get_answer: block_number = 1
get_answer: data length = 116
get_answer: sequence number (1) is ok
get_answer: checksum is ok
Let's read some data; length: 116, bytes_read: 166
get_answer: block_number = 1
get_answer: data length = 40
get_answer: sequence number (2) is ok
get_answer: checksum is ok
get_answer: all data received
We're at end of loop with end_length: 156
get_answer: exiting (len=156)
entering get_answer(36)
About to start loop ...
Let's read some data; length: 1, bytes_read: 0
We've got something to read ...
usb_interrupt_read is 85
get_answer: block_number = 6
get_answer: data length = 80
get_answer: sequence number (1) is ok
get_answer: checksum is ok
get_answer: all data received
We're at end of loop with end_length: 80
get_answer: exiting (len=80)
entering get_answer(3c)
About to start loop ...
Let's read some data; length: 1, bytes_read: 0
We've got something to read ...
usb_interrupt_read is 36
get_answer: block_number = c
get_answer: data length = 31
get_answer: sequence number (1) is ok
get_answer: checksum is ok
get_answer: all data received
We're at end of loop with end_length: 31
get_answer: exiting (len=31)
entering get_answer(40)
About to start loop ...
Let's read some data; length: 1, bytes_read: 0
We've got something to read ...
usb_interrupt_read is 29
get_answer: block_number = 10
get_answer: data length = 24
get_answer: sequence number (1) is ok
get_answer: checksum is ok
get_answer: all data received
We're at end of loop with end_length: 24
get_answer: exiting (len=24)
entering get_answer(34)
About to start loop ...
Let's read some data; length: 1, bytes_read: 0
We've got something to read ...
usb_interrupt_read is 61
get_answer: block_number = 4
get_answer: data length = 56
get_answer: sequence number (1) is ok
get_answer: checksum is ok
get_answer: all data received
We're at end of loop with end_length: 56
get_answer: exiting (len=56)
entering get_answer(35)
About to start loop ...
Let's read some data; length: 1, bytes_read: 0
We've got something to read ...
usb_interrupt_read is 22
get_answer: block_number = 5
get_answer: data length = 17
get_answer: sequence number (1) is ok
get_answer: checksum is ok
get_answer: all data received
We're at end of loop with end_length: 17
get_answer: exiting (len=17)
entering get_answer(33)
About to start loop ...
Let's read some data; length: 1, bytes_read: 0
We've got something to read ...
usb_interrupt_read is 25
get_answer: block_number = 3
get_answer: data length = 19
get_answer: sequence number (1) is ok
get_answer: checksum is ok
get_answer: all data received
We're at end of loop with end_length: 19
get_answer: exiting (len=19)
NUT $

Then we get the following repeated in the console log:

10/03/10 7:46:17 PM bcmxcp_usb[3613] entering get_answer(34)
10/03/10 7:46:17 PM bcmxcp_usb[3613] About to start loop ...
10/03/10 7:46:17 PM bcmxcp_usb[3613] Let's read some data; 
length: 1, bytes_read: 0
10/03/10 7:46:17 PM bcmxcp_usb[3613] We've got something to read ...
10/03/10 7:46:17 PM bcmxcp_usb[3613] usb_interrupt_read is -6
10/03/10 7:46:17 PM bcmxcp_usb[3613] We're at end of loop with 
end_length: 0
10/03/10 7:46:17 PM bcmxcp_usb[3613] get_answer: exiting (len=0)
10/03/10 7:46:17 PM bcmxcp_usb[3613] entering get_answer(34)
10/03/10 7:46:17 PM bcmxcp_usb[3613] About to start loop ...
10/03/10 7:46:17 PM bcmxcp_usb[3613] Let's read some data; 
length: 1, bytes_read: 0
10/03/10 7:46:17 PM bcmxcp_usb[3613] We've got something to read ...
10/03/10 7:46:17 PM bcmxcp_usb[3613] usb_interrupt_read is -6
10/03/10 7:46:17 PM bcmxcp_usb[3613] We're at end of loop with 
end_length: 0
10/03/10 7:46:17 PM bcmxcp_usb[3613] get_answer: exiting (len=0)

For reference, the bcmxcp_usb.c file I'm using is attached.

Is any of the above useful? Is the problem what you thought it 
was? Is there anything else I can test?

Thanks,
Charlie

PS. Had power outage last night while sleeping; my system didn't 
get a graceful shutdown. :-(
So I'm keen to help get this issue resolved.
-- 
    Ꮚ Charlie Garrison ♊ <garrison at zeta.org.au>
    〠 PO Box 141, Windsor, NSW 2756, Australia

O< ascii ribbon campaign - stop html mail - www.asciiribbon.org
http://www.ietf.org/rfc/rfc1855.txt
-------------- next part --------------
A non-text attachment was scrubbed...
Name: bcmxcp_usb.c
Type: application/octet-stream
Size: 13478 bytes
Desc: not available
URL: <http://lists.alioth.debian.org/pipermail/nut-upsdev/attachments/20100310/ba1fa8ef/attachment-0001.obj>