[Nut-upsuser] bcmxcp_usb can not communicate with Eaton Powerware 5110
Massimo Gais
simosagi9 at gmail.com
Thu Aug 9 15:02:40 UTC 2012
On Wed, Aug 8, 2012 at 1:32 PM, Greg Vickers <daehenoc at iinet.net.au> wrote:
> Fantastic Massimo, thank you! I have yet to replace my 5110, so if there is
> anything I can contribute, I will do.
>
> It looks like the only difference between our systems is the kernel version
> (I've put the latest rasbian image on, which has kernel 3.2.0-3-rpi).
>
Maybe the problem is specific to the RPi USB.
This is the debug from my UPS plugged to old faithful NSLU2, when I
launch the command "/lib/nut/bcmxcp_usb -DDD -a ups":
0.000000 debug level is '3'
0.017323 device 002 opened successfully
0.023706 entering get_answer(31)
0.364865 get_answer: (171 bytes) => ab 01 79 01 02 50 00 50 01
00 0e 00 01 00 10 50
0.366159 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00
00 00 00 00 00 00 00
0.367427 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
51 51 00 00 00 00 51
0.368694 00 00 00 00 00 00 00 f0 00 f0 00 00 00 f0 00 00 00 00
00 00 00 00 f0 00 00
0.369962 00 00 00 00 00 00 51 00 00 51 00 00 00 00 00 00 00 00
00 f0 00 00 00 00 00
0.371226 00 00 00 00 00 00 00 f0 18 3b ab 01 28 82 c0 01 00 02
00 00 80 0f 00 00 00
0.372613 00 00 00 00 00 00 00 00 00 00 01 00 80 40 00 00 00 00
00 00 03 00 08 16 00
0.373774 00 00 0b 00 6b
0.374896 get_answer: block_number = 1
0.376030 get_answer: data length = 121
0.377164 get_answer: sequence number (1) is ok
0.378287 get_answer: checksum is ok
0.379486 get_answer: block_number = 1
0.380620 get_answer: data length = 40
0.381664 get_answer: sequence number (2) is ok
0.381826 get_answer: checksum is ok
0.381893 get_answer: all data received
0.382289 Length of meter map: 92
While this one is the beginning of same debug when same UPS is plugged
to RPi (result is similar to what Greg posted at beginning of this
mail thread):
0.000000 debug level is '3'
0.010391 entering nutusb_open()
0.017472 device 013 opened successfully
0.021978 send_read_command: (4 bytes) => ab 01 31 23
0.026489 entering get_answer(31)
0.574934 get_answer: (8 bytes) => ab 01 79 01 02 50 00 50
0.578455 get_answer: block_number = 1
0.581920 get_answer: data length = 121
0.585234 get_answer: need to read 118 more data
0.590947 get_answer: (16 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.593093 get_answer: block_number = 1
0.595320 get_answer: data length = 121
0.597427 get_answer: need to read 110 more data
0.606950 get_answer: (24 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.609794 4f 57 45 52 57 41 52 45
0.612015 get_answer: block_number = 1
0.613425 get_answer: data length = 121
0.613543 get_answer: need to read 102 more data
0.622947 get_answer: (32 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.625209 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c
0.627201 get_answer: block_number = 1
0.629377 get_answer: data length = 121
0.631307 get_answer: need to read 94 more data
0.638944 get_answer: (40 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.641196 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00
0.643941 get_answer: block_number = 1
0.645316 get_answer: data length = 121
0.647564 get_answer: need to read 86 more data
0.654946 get_answer: (48 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.657225 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.659884 00 00 00 00 00 00 00
0.662287 get_answer: block_number = 1
0.664394 get_answer: data length = 121
0.666510 get_answer: need to read 78 more data
0.670930 get_answer: (56 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.673329 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.675561 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0.677611 get_answer: block_number = 1
0.679573 get_answer: data length = 121
0.680864 get_answer: need to read 70 more data
0.686944 get_answer: (64 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.689219 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.691553 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51
51 00 00 00
0.694208 get_answer: block_number = 1
0.696939 get_answer: data length = 121
0.697228 get_answer: need to read 62 more data
0.702946 get_answer: (72 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.705226 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.707916 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51
51 00 00 00 00 51
0.710082 00 00 00 00 00 00
0.712458 get_answer: block_number = 1
0.712587 get_answer: data length = 121
0.712641 get_answer: need to read 54 more data
0.718942 get_answer: (80 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.721205 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.723601 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51
51 00 00 00 00 51
0.725794 00 00 00 00 00 00 00 f0 00 f0 00 00 00 f0
0.727820 get_answer: block_number = 1
0.729919 get_answer: data length = 121
0.730046 get_answer: need to read 46 more data
0.734942 get_answer: (88 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.735668 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.736876 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51
51 00 00 00 00 51
0.737041 00 00 00 00 00 00 00 f0 00 f0 00 00 00 f0 00 00 00 00 00 00 00 00
0.737100 get_answer: block_number = 1
0.737161 get_answer: data length = 121
0.737214 get_answer: need to read 38 more data
0.750949 get_answer: (96 bytes) => ab 01 79 01 02 50 00 50 01 00 0e
00 01 00 10 50
0.753338 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.755479 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51
51 00 00 00 00 51
0.757730 00 00 00 00 00 00 00 f0 00 f0 00 00 00 f0 00 00 00 00 00
00 00 00 f0 00 00
0.759811 00 00 00 00 00
0.762011 get_answer: block_number = 1
0.762137 get_answer: data length = 121
0.762209 get_answer: need to read 30 more data
0.766942 get_answer: (104 bytes) => ab 01 79 01 02 50 00 50 01 00
0e 00 01 00 10 50
0.767670 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.768866 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51
51 00 00 00 00 51
0.769034 00 00 00 00 00 00 00 f0 00 f0 00 00 00 f0 00 00 00 00 00
00 00 00 f0 00 00
0.769116 00 00 00 00 00 00 51 00 00 51 00 00 00
0.769178 get_answer: block_number = 1
0.769229 get_answer: data length = 121
0.769286 get_answer: need to read 22 more data
0.782944 get_answer: (112 bytes) => ab 01 79 01 02 50 00 50 01 00
0e 00 01 00 10 50
0.785207 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.787361 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51
51 00 00 00 00 51
0.789573 00 00 00 00 00 00 00 f0 00 f0 00 00 00 f0 00 00 00 00 00
00 00 00 f0 00 00
0.791867 00 00 00 00 00 00 51 00 00 51 00 00 00 00 00 00 00 00 00 f0 00
0.794500 get_answer: block_number = 1
0.796781 get_answer: data length = 121
0.797925 get_answer: need to read 14 more data
0.800162 get_answer: (120 bytes) => ab 01 79 01 02 50 00 50 01 00
0e 00 01 00 10 50
0.802488 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.804714 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51
51 00 00 00 00 51
0.807548 00 00 00 00 00 00 00 f0 00 f0 00 00 00 f0 00 00 00 00 00
00 00 00 f0 00 00
0.809746 00 00 00 00 00 00 51 00 00 51 00 00 00 00 00 00 00 00 00
f0 00 00 00 00 00
0.812037 00 00 00 00
0.812160 get_answer: block_number = 1
0.812220 get_answer: data length = 121
0.812281 get_answer: need to read 6 more data
0.814929 get_answer: (128 bytes) => ab 01 79 01 02 50 00 50 01 00
0e 00 01 00 10 50
0.815110 4f 57 45 52 57 41 52 45 20 55 50 53 20 20 20 5c 00 00 00
00 00 00 00 00 00
0.815237 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51
51 00 00 00 00 51
0.815357 00 00 00 00 00 00 00 f0 00 f0 00 00 00 f0 00 00 00 00 00
00 00 00 f0 00 00
0.815475 00 00 00 00 00 00 51 00 00 51 00 00 00 00 00 00 00 00 00
f0 00 00 00 00 00
0.815561 00 00 00 00 00 00 00 f0 18 3b ab 01
0.815611 get_answer: block_number = 1
0.815673 get_answer: data length = 121
0.815721 get_answer: sequence number (1) is ok
0.815777 get_answer: checksum is ok
0.815852 get_answer: block_number = 1
0.815915 get_answer: data length = 0
0.815975 Communications with UPS lost: get_answer: not the right
sequence received 0!!!
...
(then the driver tries a few more times to repeat the operation, but
it fails the same way, and then about by timeout)
It seems that for some reason the call to usb_interrupt_read()
function is able only to 'nibble' 8 bytes at a time, instead of
receiving the whole 171 bytes transfer in one single gulp.
Looking at dmesg, I see that on RPi the USB is handled by dwc_otg
driver, instead of the usual ohci_hcd, and on RPi forums they noticed
that there is some issue with it, like... that dwc_otg generates on
idle 8000 interrupts per second!
I'm not too expert on USB things, but I wonder if that may affect the
communication with the UPS.
Cheers,
Massimo
More information about the Nut-upsuser
mailing list