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

Wed Mar 17 09:17:11 UTC 2010

Good evening,

On 14/03/10 at 4:01 PM +1100, Charlie Garrison 
<garrison at zeta.org.au> wrote:
>On 14/03/10 at 4:52 AM +1100, Charlie Garrison <garrison at zeta.org.au> wrote:
>
>>I don't believe I've had a 'data stale' error when running 
>>driver in debug mode. Or maybe I'm not following what you're saying.
>
>But I have now...  after running for around 8 hours in debug 
>mode; I'm now getting "Data stale" errors via upsmon:

And I ran again with debug logging to a file (rather than 
/dev/null). The results (below) don't mean much to me. I've 
snipped large chunks of it; the roll-over point is when the 
errors started, and I killed the driver & dis/connected the USB cable.

    0.000000 debug level is '1'
    0.294253 device 003-06da-0002-00-00 opened successfully
    0.297054 entering get_answer(31)
    1.048235 get_answer: (166 bytes) => ab 01 74 01 02 00 01 05 
10 00 14 00 01 00 13 35
    1.048306  31 31 35 31 30 30 30 41 20 20 20 20 20 20 20 20 20 
20 51 00 00 00 00 00 00
    1.048333  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f0 00 
f0 00 00 00 52 52 00 00
    1.048359  00 00 52 f0 e2 00 00 00 00 00 00 00 00 00 00 00 00 
00 00 00 00 00 00 00 00
    1.048385  f0 00 00 f0 00 00 f0 00 00 41 00 00 41 00 00 f0 00 
00 00 00 00 00 f0 00 00
    1.048502  1b c0 01 00 8a ab 01 28 82 82 04 00 80 0b 00 00 00 
00 00 00 00 40 00 00 00
    1.048529  00 00 05 00 80 06 08 00 50 00 00 00 00 00 00 03 00 
1b 18 00 00 00 11 00 2f
    1.048544 get_answer: block_number = 1
    1.048567 get_answer: block_number = 1
    1.050152 entering get_answer(36)
    1.497562 get_answer: (85 bytes) => ab 06 50 81 23 01 ce c7 
00 11 f4 01 f0 00 32 00
    1.497630  00 00 00 33 ba 00 00 00 00 00 c9 0a a0 00 01 00 00 
00 04 08 00 00 00 00 00
    1.497656  01 05 10 00 00 00 00 00 00 00 1f 35 31 31 35 31 30 
30 30 41 20 20 20 20 20
    1.497679  20 20 55 58 32 30 35 41 30 35 37 37 20 20 20 20 20 
20 35
    1.497694 get_answer: block_number = 6
    1.502436 entering get_answer(3c)
    1.736135 get_answer: (36 bytes) => ab 0c 1f 81 f0 00 32 00 
0d 00 43 30 f4 01 d8 00
    1.736207  fe 00 00 00 02 01 ca 00 16 01 00 00 00 00 4b 01 00 
00 00 0c
    1.736223 get_answer: block_number = c
    1.736273 entering init_command_map()
    1.738051 entering get_answer(40)
    1.944112 get_answer: (29 bytes) => ab 10 18 81 16 01 31 33 
34 35 36 3b 3c 3f 40 42
    1.944173  43 89 8a 8b 91 93 95 98 a0 b1 b2 cf 56
    1.944188 get_answer: block_number = 10
...................
226744.228202   entering get_answer(34)
226744.555519   get_answer: (61 bytes) => ab 04 38 81 bf 00 00 
00 d5 00 00 00 00 5c 49 42
226744.555582    00 5c 49 42 00 58 db 41 64 00 00 00 2d 04 00 00 
fe 00 00 00 00 00 00 00 1c
226744.555606    00 00 00 00 00 54 3f ad 47 91 40 e8 03 00 00 fe 
00 00 00 d2
226744.555621   get_answer: block_number = 4
226744.557253   entering get_answer(35)
226744.715246   get_answer: (22 bytes) => ab 05 11 81 00 00 00 
00 00 00 00 00 00 00 00 00
226744.715310    00 00 00 00 00 be
226744.715325   get_answer: block_number = 5
226744.717475   entering get_answer(33)
226744.907246   get_answer: (25 bytes) => ab 03 13 81 50 c2 00 
00 05 00 00 00 00 00 00 00
226744.907307    00 00 00 00 00 00 00 a7 00
226744.907322   get_answer: block_number = 3
226746.228137   entering get_answer(34)
226746.555218   get_answer: (61 bytes) => ab 04 38 81 c9 00 00 
00 e1 00 00 00 00 5c 49 42
226746.555294    00 5c 49 42 00 58 db 41 64 00 00 00 2d 04 00 00 
fe 00 00 00 00 00 00 00 1c
226746.555318    00 00 00 00 00 54 3f ad 47 91 40 e8 03 00 00 fe 
00 00 00 bc
226746.555333   get_answer: block_number = 4
226746.557126   entering get_answer(35)
226746.715236   get_answer: (22 bytes) => ab 05 11 81 00 00 00 
00 00 00 00 00 00 00 00 00
226746.715301    00 00 00 00 00 be
226746.715316   get_answer: block_number = 5
226746.717175   entering get_answer(33)
226746.907241   get_answer: (25 bytes) => ab 03 13 81 50 c2 00 
00 05 00 00 00 00 00 00 00
226746.907300    00 00 00 00 00 00 00 a7 00
226746.907315   get_answer: block_number = 3
    0.000000 debug level is '1'
    0.442737 device 002-06da-0002-00-00 opened successfully
    0.446052 entering get_answer(31)
    1.196181 get_answer: (166 bytes) => ab 01 74 01 02 00 01 05 
10 00 14 00 01 00 13 35
    1.196246  31 31 35 31 30 30 30 41 20 20 20 20 20 20 20 20 20 
20 51 00 00 00 00 00 00
    1.196273  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f0 00 
f0 00 00 00 52 52 00 00
    1.196300  00 00 52 f0 e2 00 00 00 00 00 00 00 00 00 00 00 00 
00 00 00 00 00 00 00 00
    1.196326  f0 00 00 f0 00 00 f0 00 00 41 00 00 41 00 00 f0 00 
00 00 00 00 00 f0 00 00
    1.196352  1b c0 01 00 8a ab 01 28 82 82 04 00 80 0b 00 00 00 
00 00 00 00 40 00 00 00
    1.196379  00 00 05 00 80 06 08 00 50 00 00 00 00 00 00 03 00 
1b 18 00 00 00 11 00 2f
    1.196393 get_answer: block_number = 1
    1.196417 get_answer: block_number = 1
    1.202653 entering get_answer(36)
    1.628125 get_answer: (85 bytes) => ab 06 50 81 23 01 ce c7 
00 11 f4 01 f0 00 32 00
    1.628192  00 00 00 33 ba 00 00 00 00 00 c9 0a a0 00 01 00 00 
00 04 08 00 00 00 00 00
    1.628218  01 05 10 00 00 00 00 00 00 00 1f 35 31 31 35 31 30 
30 30 41 20 20 20 20 20
    1.628241  20 20 55 58 32 30 35 41 30 35 37 37 20 20 20 20 20 
20 35
    1.628256 get_answer: block_number = 6

So, I've got all processes running and upsmon doing it's job, 
but it's not a reliable setup. After a day or two the driver has 
to give up and won't work again until after UPS has been dis/connected.

Note, I didn't think to try dis/connecting the UPS before 
killing the driver. If/when the problem returns I will try that 
before killing the driver.

Is there anything else I can do to help with testing?

Thanks,
Charlie

-- 
    Ꮚ 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