Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP

Loading…

USB issue - Libusb_interrupt_transfer #79

Closed
DAFlippers opened this Issue · 22 comments

7 participants

@DAFlippers

If USB_CTRL_TIMEOUT set to <50ms then first tx transfer usually returns 0 bytes transferred and timeout but data is actually sent out on USB.

During Read the data can be seen on the USB but is sometimes not returned by libusb_interrupt_transfer - see second read below.

Debug below from program and corresponding USB analyser. You can see first tx return 0 and timeout but data is sent out on USB.

More detail can be provided if required.

Libusb-1.0 is latest version. Program works flawlessly on other platforms running ubuntu/suse.

David

DEBUG FROM PROGRAM RUNNING ON RPi

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 00 00 00 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned -7 and transferred 0
Write returned -7
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=0 buf[0] 03 buf[1] 00 buf[2] 04 buf [3] 00 buf[4] 00 loop 0
Read returned 0
WS is 4

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 00 00 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 0 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 1 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 2 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 3 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 4 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 5 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 6 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 7 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 8 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 9 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 10 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 11 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 12 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 13 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 14 returned -7
RX Interrupt transfer returned -7 and transferred 0
Read 5 expect buf[1]=1 buf[0] 00 buf[1] 00 buf[2] 00 buf [3] 00 buf[4] 00 loop 15 returned -7
Read returned -1

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 3c 00 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 78 00 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 b4 00 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 f0 00 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 2c 01 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 68 01 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 48 buf [3] 03 buf[4] 0d loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 a4 01 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 e0 01 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 1c 02 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 58 02 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 94 02 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 d0 02 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

Calling usb_interrupt_transfer with weydev->udev: 0x1921cc0 ,ep 0x0003, buffer 03 01 0c 03 00 00h ..., Len 0040h Timeout 10ms
TX Interrupt transfer returned 0 and transferred 64
Write returned 0
RX Interrupt transfer returned 0 and transferred 64
Read 4 expect buf[1]=1 buf[0] 03 buf[1] 01 buf[2] 00 buf [3] 00 buf[4] 00 loop 0
Read returned 0

ELLISYS USB ANALYSER OUTPUT - FILTERED FOR ENDPOINT 3

Item Device Endpoint Interface Speed Payload Time
Start of Frame (8,467) FS 1,670 -> 1,944 0.000 871 383
OUT transaction 4 3 ACK FS 64 bytes (03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.466 503 700
IN transaction 4 3 ACK FS 64 bytes (03 00 04 00 00 00 FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF BD A3) 8.466 875 483
Start of Frame (11) FS 1,945 -> 1,955 8.467 500 250
OUT transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.477 875 017
Start of Frame (337) FS 1,956 -> 244 8.478 499 767
OUT transaction 4 3 ACK FS 64 bytes (03 01 3C 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.814 860 233
Start of Frame (6) FS 245 -> 250 8.815 485 000
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 8.820 610 000
Start of Frame (11) FS 251 -> 261 8.821 484 733
OUT transaction 4 3 ACK FS 64 bytes (03 01 78 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.831 609 500
Start of Frame (7) FS 262 -> 268 8.832 484 250
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 8.838 609 200
Start of Frame (11) FS 269 -> 279 8.839 483 950
OUT transaction 4 3 ACK FS 64 bytes (03 01 B4 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.849 608 717
Start of Frame (7) FS 280 -> 286 8.850 483 450
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 8.856 608 417
Start of Frame (11) FS 287 -> 297 8.857 483 150
OUT transaction 4 3 ACK FS 64 bytes (03 01 F0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.868 232 900
Start of Frame (7) FS 298 -> 304 8.868 482 667
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 01 00 48 03 0D 02 01 00 48 03 0D 02 02 00 80 07 1C 02 03 00 48 03 0D 02 03 00 48 03 0D 02 04 00 80 02 00 02 04 00 80 02 00 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 8.874 607 617
Start of Frame (11) FS 305 -> 315 8.875 482 367
OUT transaction 4 3 ACK FS 64 bytes (03 01 2C 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.885 732 117
Start of Frame (7) FS 316 -> 322 8.886 481 883
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 48 03 0D 02 01 00 48 03 0D 02 02 00 80 07 1C 02 03 00 BD A3) 8.892 606 833
Start of Frame (11) FS 323 -> 333 8.893 481 567
OUT transaction 4 3 ACK FS 64 bytes (03 01 68 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.903 731 350
Start of Frame (7) FS 334 -> 340 8.904 481 100
IN transaction 4 3 ACK FS 64 bytes (03 01 48 03 0D 02 03 00 48 03 0D 02 04 00 80 02 00 02 04 00 80 02 00 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 8.910 606 033
Start of Frame (11) FS 341 -> 351 8.911 480 783
OUT transaction 4 3 ACK FS 64 bytes (03 01 A4 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.921 730 567
Start of Frame (7) FS 352 -> 358 8.922 480 317
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 8.928 605 250
Start of Frame (11) FS 359 -> 369 8.929 480 000
OUT transaction 4 3 ACK FS 64 bytes (03 01 E0 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.939 729 767
Start of Frame (7) FS 370 -> 376 8.940 479 517
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 8.946 604 450
Start of Frame (11) FS 377 -> 387 8.947 479 200
OUT transaction 4 3 ACK FS 64 bytes (03 01 1C 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.957 728 983
Start of Frame (8) FS 388 -> 395 8.958 478 733
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 8.965 603 600
Start of Frame (11) FS 396 -> 406 8.966 478 367
OUT transaction 4 3 ACK FS 64 bytes (03 01 58 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.976 728 150
Start of Frame (6) FS 407 -> 412 8.977 477 900
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 8.982 602 883
Start of Frame (11) FS 413 -> 423 8.983 477 633
OUT transaction 4 3 ACK FS 64 bytes (03 01 94 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 8.993 727 400
Start of Frame (7) FS 424 -> 430 8.994 477 150
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 9.000 602 100
Start of Frame (11) FS 431 -> 441 9.001 476 850
OUT transaction 4 3 ACK FS 64 bytes (03 01 D0 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 9.011 726 600
Start of Frame (7) FS 442 -> 448 9.012 476 350
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 BD A3) 9.018 601 317
Start of Frame (17) FS 449 -> 465 9.019 476 050
OUT transaction 4 3 ACK FS 64 bytes (03 01 0C 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 9.036 350 533
Start of Frame (7) FS 466 -> 472 9.036 475 300
IN transaction 4 3 ACK FS 64 bytes (03 01 00 00 00 00 FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF BD A3) 9.042 600 267
Start of Frame (8,411) FS 473 -> 691 9.043 475 000
OUT transaction 4 3 ACK FS 64 bytes (03 02 02 2B 00 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 17.453 109 717
Start of Frame FS 692 17.454 106 250
OUT transaction 4 3 ACK FS 64 bytes (03 02 02 2B 00 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 17.454 231 467
Start of Frame (124) FS 693 -> 816 17.455 106 200
IN transaction 4 3 ACK FS 64 bytes (03 02 03 2C 00 C8 FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF BD A3) 17.578 976 000
Start of Frame (7) FS 817 -> 823 17.579 100 767
OUT transaction 4 3 ACK FS 64 bytes (03 03 02 2B 00 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 17.585 103 933
Start of Frame FS 824 17.586 100 467
OUT transaction 4 3 ACK FS 64 bytes (03 03 02 2B 00 C8 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 17.586 225 683
Start of Frame (2,392) FS 825 -> 1,168 17.587 100 433
OUT transaction 4 3 ACK FS 64 bytes (03 02 02 2B 80 8B 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 19.978 745 767
Start of Frame (4) FS 1,169 -> 1,172 19.978 995 550
IN transaction 4 3 ACK FS 64 bytes (03 02 03 2C 80 8B FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF BD A3) 19.982 120 633
Start of Frame (4) FS 1,173 -> 1,176 19.982 995 367
OUT transaction 4 3 ACK FS 64 bytes (03 03 02 2B 80 8B 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00) 19.986 245 433
Start of Frame (10,194) FS 1,177 -> 1,130 19.986 995 183

@DAFlippers

Just to add that i have checked this on more than one RPi.

David

@DAFlippers

I have repeated testing following update to Linux version 3.2.27+ #24 PREEMPT and I still see the same problem with libusb_interrupt_transfer calls so this issue is not resolved.

My setup is very simple: RPi, Wired Ethernet connection, HDMI -> DVI connection to monitor and single USB connection to a USB 1:4 deskswitch - HID combined keyboard/mouse that my program 'talks' to on endpoint 3.

Note that I can add debug to my program and I have an external USB analyser (ellisys USB explorer) to capture the USB traffic should any testing/further information be required - just let me know what you require and I can do it.

David

@DAFlippers DAFlippers closed this
@DAFlippers DAFlippers reopened this
@popcornmix
Owner

I'm afraid I don't know enough to usefully comment. I'll try and get naren/gsh to look at this.

I don't know if it's related to this issue:
#72

I have found sdcard driver disabling interrupts for >100ms. You can avoid this with command line options:
sdhci-bcm2708.missing_status=0 sdhci-bcm2708.sync_after_dma=0
but it does cause problems with some sdcards. You could also try the patch in the pull request, but I don't think that is safe either.

@DAFlippers

I should have added that my cmdline.txt file wasupdated to:

dwc_otg.microframe_schedule=1, sdhci-bcm2708.missing_status=0, sdhci-bcm2708.sync_after_dma=0 dwc_otg.lpm_enable=0 rpitestmode=1 console=ttyAMA0,115200 kgdboc=ttyAMA0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 rootwait

so this is not the fix.

David

@raspberrypi
@DAFlippers

It is a 4 port KVM switch that has USB keyboard and Mouse input and 4 USB ports that can be connected to 4 different computers http://www.weytec.com/en/products/wey-keyboards/usb-deskswitch-ii-14/overview/.

I am using endpoint 3 to communicate with the device. Libusb_control_transfer() calls have never failed on RPi but libusb_interrupt_transfer have a very high failure rate so much so I have rarely successfully completed the 15 or so calls used to get configuration from the device at startup.

I have just installed the software on a pico ITX Atom based board running Fedora and it runs without issue. The only platform so far to have an issue is RPi.

David

@popcornmix
Owner

gsh thinks you might be seeing an instance of his split transactions getting lost issue:

"Yeah I still think it's just the OUT case of the split interrupts...

Only useful information would be them putting an external hub in and then capturing the data between the pi and the hub, this should then show the failing splits"

@DAFlippers

I placed a powered hub between RPi and USB switch and captured USB data between RPi and hub twice. I then removed the hub and captured data once.

Program log and USB logs posted in https://github.com/DAFlippers/RPi-data - forgive me if not posted correctly - I'm just learning the ropes.

You'll need the ellisys software http://www.ellisys.com/products/usbex200/download.php to view the .ufo files.

David

@grigorig

DAFlippers, have you really added these commas into cmdline.txt? This might be harmful.

@DAFlippers

D'oh!

The perils of copy paste and not checking...

Unfortunately stil the same result when commas removed.

David

@ghollingworth

Not sure the traces are particularly useful... The captures need to be at the same time and preferably interleaved! I've got a LeCroy analyser for this, its quite useful!

There are clearly failing SPLIT IN transactions recorded but I didn't find any SPLIT OUT transactions

Doesn't help that the GUI is a bit difficult to navigate and very very slow to do anything!

Will assume for the moment it's the same problem as already being seen and will have to try again when we have a fix

@DAFlippers

Thanks for input.

I guess I could edit the program debug and USB trace together but I find if I filter ep 3 it is relatively easy to cross reference. Note the debug and trace should be for the same transactions, i.e. the files numbered 01 were logged at the same time but it looks like I screwed up on the nohub :(. The program is writing and reading 64 bytes per message so it isn't massive but it just doesn't see the read data although I can see the data on the bus so RPi is instigating the read but the call isn't returning it.

I'll rpi-update and repeat making sure logs tie up.

David

@ghollingworth
@DAFlippers

Hi Gordon,

I've had to fight but I have loaded log files to https://github.com/DAFlippers/27Aug. RPi running 3.2.27+ #66 PREEMPT and cmdline.txt is in the zip.

NoHub Device 4 ep 3 and Hub Device 6 ep 3. You can filter endpoints by putting 3 in box under column heading and similarly 4 or 6 in device filter box.

No hub transactions start at 3.316 214 133 and Hub at 5.952 894 533.

I hope you had a great holiday.

David

@ghollingworth

Yes the problem is just SPLIT transactions being dropped exactly the same as we've already seen...

I'd suggest trying the latest kernel updates from Dom since the low latency changes are now set as default, it'd be interesting to see how much of a difference this makes for you...

Gordon

@DAFlippers

Hi Gordon,

Running 3.2.27+ #114 PREEMPT Tue Sep 4 00:15:33.

The first run looked promising however more thorough testing shows little, if any, improvement. Simple interrupt_transfer write calls do not return success even when data was transmitted on USB and USB data read from bus is not returned on read call.

Any suggestions?

David

@msmeissn

The problem is not with interrupt transfers per-se

Its that we can only do one camera session ... we exchange multiple bulk transfers back and forth which work fine
and wrap it up with a PTP closesession in the end.

A new session then does not open anymore, nbulk transfers timeout.

@DAFlippers

It depends how the code handles errors. I have found libusb_interrupt_transfer reads on other hardware can return a timeout but actually has transferred the data so a timeout might not 'really' be a timeout. On RPi however the returned data is simply missing some of the time.

David

@ghollingworth ghollingworth was assigned
@piotr-e

When can we expect fix USB driver?

@piotr-e

I see blinking SD card led during easycap working. Why does SD card working during easycap working? I don't write any data to SD in this moment.

@swarren swarren referenced this issue from a commit in swarren/linux-rpi
@dmonakhov dmonakhov jbd2: fix ERR_PTR dereference in jbd2__journal_start
If start_this_handle() failed handle will be initialized
to ERR_PTR() and can not be dereferenced.

paging request at fffffffffffffff6
IP: [<ffffffff813c073f>] jbd2__journal_start+0x18f/0x290
PGD 200e067 PUD 200f067 PMD 0
Oops: 0000 [#1] SMP
Modules linked in: cpufreq_ondemand acpi_cpufreq freq_table mperf coretemp kvm_intel kvm crc32c_intel ghash_clmulni_intel microcode sg xhci_hcd button sd_mod crc_t10dif aesni_intel ablk_helper cryptd lrw aes_x86_64 xts gf128mul ahci libahci pata_acpi ata_generic dm_mirror dm_region_hash dm_log dm_mod
CPU 0 journal commit I/O error

Pid: 2694, comm: fio Not tainted 3.8.0-rc3+ #79                  /DQ67SW
RIP: 0010:[<ffffffff813c073f>]  [<ffffffff813c073f>] jbd2__journal_start+0x18f/0x290
RSP: 0018:ffff880233b8ba58  EFLAGS: 00010292
RAX: 00000000ffffffe2 RBX: ffffffffffffffe2 RCX: 0000000000000006
RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff82128f48
RBP: ffff880233b8ba98 R08: 0000000000000000 R09: ffff88021440a6e0

Signed-off-by: Dmitry Monakhov <dmonakhov@openvz.org>
Signed-off-by: "Theodore Ts'o" <tytso@mit.edu>
df05c1b
@ghollingworth

Can you test this again with the latest updated kernel (using sudo rpi-update) be interesting to see if it is still a problem

@DAFlippers

Hi Gordon,

I tested before rpi-update and then after.

Before the reads were sometimes successful and writes were mostly successful.

Following the update and woohoo it looks like it's working.

Was this a recent update as I had updated the firmware a fortnight or so ago?

David

@DAFlippers DAFlippers closed this
@swarren swarren referenced this issue from a commit in swarren/linux-rpi
Borislav Petkov x86/boot: Further compress CPUs bootup message
Turn it into (for example):

[    0.073380] x86: Booting SMP configuration:
[    0.074005] .... node   #0, CPUs:          #1   #2   #3   #4   #5   #6   #7
[    0.603005] .... node   #1, CPUs:     #8   #9  #10  #11  #12  #13  #14  #15
[    1.200005] .... node   #2, CPUs:    #16  #17  #18  #19  #20  #21  #22  #23
[    1.796005] .... node   #3, CPUs:    #24  #25  #26  #27  #28  #29  #30  #31
[    2.393005] .... node   #4, CPUs:    #32  #33  #34  #35  #36  #37  #38  #39
[    2.996005] .... node   #5, CPUs:    #40  #41  #42  #43  #44  #45  #46  #47
[    3.600005] .... node   #6, CPUs:    #48  #49  #50  #51  #52  #53  #54  #55
[    4.202005] .... node   #7, CPUs:    #56  #57  #58  #59  #60  #61  #62  #63
[    4.811005] .... node   #8, CPUs:    #64  #65  #66  #67  #68  #69  #70  #71
[    5.421006] .... node   #9, CPUs:    #72  #73  #74  #75  #76  #77  #78  #79
[    6.032005] .... node  #10, CPUs:    #80  #81  #82  #83  #84  #85  #86  #87
[    6.648006] .... node  #11, CPUs:    #88  #89  #90  #91  #92  #93  #94  #95
[    7.262005] .... node  #12, CPUs:    #96  #97  #98  #99 #100 #101 #102 #103
[    7.865005] .... node  #13, CPUs:   #104 #105 #106 #107 #108 #109 #110 #111
[    8.466005] .... node  #14, CPUs:   #112 #113 #114 #115 #116 #117 #118 #119
[    9.073006] .... node  #15, CPUs:   #120 #121 #122 #123 #124 #125 #126 #127
[    9.679901] x86: Booted up 16 nodes, 128 CPUs

and drop useless elements.

Change num_digits() to hpa's division-avoiding, cell-phone-typed
version which he went at great lengths and pains to submit on a
Saturday evening.

Signed-off-by: Borislav Petkov <bp@suse.de>
Cc: huawei.libin@huawei.com
Cc: wangyijing@huawei.com
Cc: fenghua.yu@intel.com
Cc: guohanjun@huawei.com
Cc: paul.gortmaker@windriver.com
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Thomas Gleixner <tglx@linutronix.de>
Link: http://lkml.kernel.org/r/20130930095624.GB16383@pd.tnic
Signed-off-by: Ingo Molnar <mingo@kernel.org>
a17bce4
@nereeb nereeb referenced this issue from a commit in nereeb/linux
@tytso tytso ext2,ext3,ext4: don't inherit APPEND_FL or IMMUTABLE_FL for new inodes
commit 1cd9f09 upstream.

This doesn't make much sense, and it exposes a bug in the kernel where
attempts to create a new file in an append-only directory using
O_CREAT will fail (but still leave a zero-length file).  This was
discovered when xfstests #79 was generalized so it could run on all
file systems.

Signed-off-by: "Theodore Ts'o" <tytso@mit.edu>
Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>
305b7dd
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.