On Wed, Aug 8, 2012 at 1:32 PM, Greg Vickers <daehe...@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

_______________________________________________
Nut-upsuser mailing list
Nut-upsuser@lists.alioth.debian.org
http://lists.alioth.debian.org/cgi-bin/mailman/listinfo/nut-upsuser

Reply via email to