Heimdall icon indicating copy to clipboard operation
Heimdall copied to clipboard

Published 20 hours ago • verified publisher icon Benjamin-Dobell

Fix USB handling and timeouts for newer devices

Open deriamis opened this issue 8 years ago • 27 comments

This commit should fix #228 #230 #209 #276 #190 #307 #141 #225 #286 for most new devices (they were all related to the same problems). The issues found were:

  • kEmptyTransferAfter should no longer be the default (apparently) in most cases. I've instances where this was being used by default to explicit kEmptyTransferNone, which fixed a lot of the warnings my S5 was getting. I assume this is the case for all newer devices, but it may need customization of some kind if there are further problems.
  • libusb_reset_device() must now be called after releasing the interface, since this is no longer being done by the device itself upon ending the session. Again, I assume this is the case for newer devices, but doing it ourselves simply ensures the reset happens even if the device also does it. Not resetting the device can result in --no-reboot leaving the device non-responsive to further sessions until it's unplugged and reattached.
  • The packet timeout was too short, which was causing occasional timeout reports. It was especially bad when the device was connected to a USB3.0 port, since the speed negotiations seemed to be pushing the response times just past the timeouts, making it impossible to connect to the device at all. Doubling the default send and receive timeout seems to have resolved all of these issues on my S5.

deriamis avatar Feb 26 '16 09:02 deriamis

I'm going to take back the last one being completely fixed on USB3.0, but it is significantly better at least when downloading the PIT. USB2.0 works without any problems. I still get the occasional "WARNING: Empty bulk transfer after sending packet failed. Continuing anyway..." as well, but far fewer and they don't really cause problems.

deriamis avatar Feb 26 '16 09:02 deriamis

Could you please separate these into 3 separate commits?

  • libusb_reset_device() must now be called after releasing the interface, since this is no longer being done by the device itself upon ending the session. Again, I assume this is the case for newer devices, but doing it ourselves simply ensures the reset happens even if the device also does it. Not resetting the device can result in --no-reboot leaving the device non-responsive to further sessions until it's unplugged and reattached.
  • The packet timeout was too short, which was causing occasional timeout reports. It was especially bad when the device was connected to a USB3.0 port, since the speed negotiations seemed to be pushing the response times just past the timeouts, making it impossible to connect to the device at all. Doubling the default send and receive timeout seems to have resolved all of these issues on my S5.

I will very happily merge both of these - thanks for the awesome work.

  • kEmptyTransferAfter should no longer be the default (apparently) in most cases. I've instances where this was being used by default to explicit kEmptyTransferNone, which fixed a lot of the warnings my S5 was getting. I assume this is the case for all newer devices, but it may need customization of some kind if there are further problems.

Definitely useful information, unfortunately I can't merge this because older devices do require the use of kEmptyTransferAfter, and we really don't want to break backwards compatibility or it will really confuse users. Ideally we need to come up with a solution that works for all devices.

Also, what model is your S5 and what is the firmware version the secondary bootloader was included with? I ask this because I also own a S5 (G900I) and it's running flawlessly with whatever secondary bootloader I have on there (it's not with me at the moment so I can't provide the version unfortunately).

Benjamin-Dobell avatar Feb 27 '16 14:02 Benjamin-Dobell

I also own a S5 (G900I) and it's running flawlessly with whatever secondary bootloader I have on there

Sorry, to clarify, I mean running flawlessly with the current master build i.e. It doesn't require the changes you've mentioned.

Benjamin-Dobell avatar Feb 27 '16 14:02 Benjamin-Dobell

Sorry for the delay - this week has been... hectic. I'll certainly split those commits for you later on this week. I actually have Cyanogenmod installed right now, but at the time I was seeing these issues, I had a stock 5.1.1 ROM on a T-Mobile SM-G900T. It was factory reconditioned when I bought it, so I imagine it would have been the latest SBL. I'm not sure how to get the actual SBL version, though - I'm a Linux administrator with some programming experience, not an Android expert. How would I get that information for you?

deriamis avatar Mar 02 '16 06:03 deriamis

Any update on this?

Arzte avatar Apr 15 '16 19:04 Arzte

I'm having this same issue, Samsung Galaxy S4, international, non-LTE version (GT-i9500)

C:.......\Heimdall Suite>heimdall detect Device detected

C:.......\Heimdall Suite>heimdall flash --RECOVERY ....\cm-12.1-20160417-NIGHTLY-i9500-recovery.img --no-reboot --verbose Heimdall v1.4.0

Copyright (c) 2010-2013, Benjamin Dobell, Glass Echidna http://www.glassechidna.com.au/

This software is provided free of charge. Copying and redistribution is encouraged.

If you appreciate this software and you would like to support future development please consider donating: http://www.glassechidna.com.au/donate/

Initialising connection... Detecting device... Manufacturer: "SAMSUNG" Product: "Gadget Serial"

        length: 18
  device class: 2
           S/N: 0
       VID:PID: 04E8:685D
     bcdDevice: 021B

iMan:iProd:iSer: 1:2:0 nb confs: 1

interface[0].altsetting[0]: num endpoints = 1 Class.SubClass.Protocol: 02.02.01 endpoint[0].address: 83 max packet size: 0010 polling interval: 09

interface[1].altsetting[0]: num endpoints = 2 Class.SubClass.Protocol: 0A.00.00 endpoint[0].address: 81 max packet size: 0200 polling interval: 00 endpoint[1].address: 02 max packet size: 0200 polling interval: 00 Claiming interface... Setting up interface...

Initialising protocol... WARNING: Control transfer #2 failed. Result: -7 WARNING: Control transfer #3 failed. Result: -7 WARNING: Control transfer #4 failed. Result: -7 WARNING: Control transfer #5 failed. Result: -7 WARNING: Control transfer #6 failed. Result: -9 ERROR: Failed to send data: "ODIN" Releasing device interface...

C:.......\Heimdall Suite>

ghost avatar Apr 17 '16 23:04 ghost

@richieacc You're running 1.4.0, please try the latest from master before commenting on issues that may have already been fixed.

Benjamin-Dobell avatar Apr 18 '16 00:04 Benjamin-Dobell

@Benjamin-Dobell Thanks! I read about the update after posting the comment. I have built Heimdall from source, and it worked.

ghost avatar Apr 18 '16 08:04 ghost

Hey, I just cloned and built Heimdall from source and get this error for a GT-S7580:

sudo heimdall print-pit --verbose

Heimdall v1.4.1

Copyright (c) 2010-2014 Benjamin Dobell, Glass Echidna
http://www.glassechidna.com.au/

This software is provided free of charge. Copying and redistribution is
encouraged.

If you appreciate this software and you would like to support future
development please consider donating:
http://www.glassechidna.com.au/donate/

Initialising connection...
Detecting device...

            length: 18
      device class: 2
               S/N: 3
           VID:PID: 04E8:685D
         bcdDevice: 0001
   iMan:iProd:iSer: 2:1:3
          nb confs: 1

interface[0].altsetting[0]: num endpoints = 1
   Class.SubClass.Protocol: 02.02.01
       endpoint[0].address: 83
           max packet size: 0040
          polling interval: 05

interface[1].altsetting[0]: num endpoints = 2
   Class.SubClass.Protocol: 0A.00.00
       endpoint[0].address: 81
           max packet size: 0200
          polling interval: 20
       endpoint[1].address: 02
           max packet size: 0200
          polling interval: 20
Claiming interface...
Setting up interface...
libusbx: error [op_set_interface] setintf failed error -1 errno 110
ERROR: Setting up interface failed!
Releasing device interface...

Edit: Ok, like always.. After posting this and restarting the device again it successfully goes further now:

Setting up interface...

Initialising protocol...
Protocol initialisation successful.

Beginning session...
WARNING: Empty bulk transfer after sending packet failed. Continuing anyway...

Some devices may take up to 2 minutes to respond.
Please be patient!

WARNING: Empty bulk transfer after sending packet failed. Continuing anyway...
Session begun.

Downloading device's PIT file...
WARNING: Empty bulk transfer after sending packet failed. Continuing anyway...
WARNING: Empty bulk transfer after sending packet failed. Continuing anyway...

It's writing this message several times until the phone restarts...

sosnet avatar Apr 22 '16 17:04 sosnet

@sosnet did you apply this patch?

EvanCarroll avatar Apr 24 '16 20:04 EvanCarroll

@evancarroll Oh sorry, my mistake. I thought this commit was already merged into the master branch. Anyway, it worker after some more tries.

sosnet avatar Apr 24 '16 21:04 sosnet

@sosnet still shows not merged.. Just hit the merge button.

EvanCarroll avatar Jun 02 '16 00:06 EvanCarroll

Just hit the merge button.

And break support for thousands of people's devices? No, thanks :wink:

As mentioned, if the pull request is split up into 2-3 smaller pieces it's easier for me to test and merge each of the functional changes individually.

Benjamin-Dobell avatar Jun 02 '16 01:06 Benjamin-Dobell

I tried this patch and it didn't work for me:

giles@BP0039a:~/Heimdall/build/bin$ git log -1
commit 81d2964b6c254d09506121bce16e482292c29c4b
Author: Ryan Egesdahl <[email protected]>
Date:   Fri Feb 26 03:24:43 2016 -0600

    Fix USB handling and timeouts for newer devices
giles@BP0039a:~/Heimdall/build/bin$ sudo ./heimdall print-pit --verbose --usb-log-level debug
Heimdall v1.4.1

Copyright (c) 2010-2014 Benjamin Dobell, Glass Echidna
http://www.glassechidna.com.au/

This software is provided free of charge. Copying and redistribution is
encouraged.

If you appreciate this software and you would like to support future
development please consider donating:
http://www.glassechidna.com.au/donate/

Initialising connection...
Detecting device...
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.008205] [00001b3c] libusb: debug [libusb_get_device_list] 
[ 0.008274] [00001b3c] libusb: debug [discovered_devs_append] need to increase capacity
[ 0.008297] [00001b3c] libusb: debug [libusb_get_device_descriptor] 
[ 0.008312] [00001b3c] libusb: debug [libusb_get_device_descriptor] 
[ 0.008327] [00001b3c] libusb: debug [libusb_get_device_descriptor] 
[ 0.008341] [00001b3c] libusb: debug [libusb_get_device_descriptor] 
[ 0.008355] [00001b3c] libusb: debug [libusb_get_device_descriptor] 
[ 0.008369] [00001b3c] libusb: debug [libusb_get_device_descriptor] 
[ 0.008383] [00001b3c] libusb: debug [libusb_get_device_descriptor] 
[ 0.008397] [00001b3c] libusb: debug [libusb_get_device_descriptor] 
[ 0.008416] [00001b3c] libusb: debug [libusb_open] open 1.18
[ 0.008489] [00001b3c] libusb: debug [usbi_add_pollfd] add fd 11 events 4
[ 0.008525] [00001b3c] libusb: debug [libusb_get_device_descriptor] 
[ 0.008545] [00001b3c] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.008600] [00001b3c] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.008622] [00001b3c] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
[ 0.008729] [00001b3c] libusb: debug [handle_events] poll() returned 1
[ 0.008789] [00001b3c] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=4
[ 0.008818] [00001b3c] libusb: debug [handle_control_completion] handling completion status 0
[ 0.008846] [00001b3c] libusb: debug [disarm_timerfd] 
[ 0.008874] [00001b3c] libusb: debug [usbi_handle_transfer_completion] transfer 0x1350350 has callback 0x7ff3b72d80b0
[ 0.008900] [00001b3c] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.008947] [00001b3c] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.008995] [00001b3c] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.009023] [00001b3c] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
[ 0.009115] [00001b3c] libusb: debug [handle_events] poll() returned 1
[ 0.009169] [00001b3c] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=16
[ 0.009196] [00001b3c] libusb: debug [handle_control_completion] handling completion status 0
[ 0.009222] [00001b3c] libusb: debug [disarm_timerfd] 
[ 0.009248] [00001b3c] libusb: debug [usbi_handle_transfer_completion] transfer 0x1350350 has callback 0x7ff3b72d80b0
[ 0.009274] [00001b3c] libusb: debug [sync_transfer_cb] actual_length=16
      Manufacturer: "SAMSUNG"
[ 0.009329] [00001b3c] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.009366] [00001b3c] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.009393] [00001b3c] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
[ 0.009480] [00001b3c] libusb: debug [handle_events] poll() returned 1
[ 0.009509] [00001b3c] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=4
[ 0.009532] [00001b3c] libusb: debug [handle_control_completion] handling completion status 0
[ 0.009558] [00001b3c] libusb: debug [disarm_timerfd] 
[ 0.009583] [00001b3c] libusb: debug [usbi_handle_transfer_completion] transfer 0x1350350 has callback 0x7ff3b72d80b0
[ 0.009609] [00001b3c] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.009638] [00001b3c] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.009674] [00001b3c] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.009701] [00001b3c] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
[ 0.009773] [00001b3c] libusb: debug [handle_events] poll() returned 1
[ 0.009803] [00001b3c] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=38
[ 0.009827] [00001b3c] libusb: debug [handle_control_completion] handling completion status 0
[ 0.009853] [00001b3c] libusb: debug [disarm_timerfd] 
[ 0.009878] [00001b3c] libusb: debug [usbi_handle_transfer_completion] transfer 0x1350350 has callback 0x7ff3b72d80b0
[ 0.009903] [00001b3c] libusb: debug [sync_transfer_cb] actual_length=38
           Product: "SAMSUNG USB DRIVER"
[ 0.009955] [00001b3c] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.009990] [00001b3c] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.010024] [00001b3c] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
[ 0.010097] [00001b3c] libusb: debug [handle_events] poll() returned 1
[ 0.010129] [00001b3c] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=4
[ 0.010152] [00001b3c] libusb: debug [handle_control_completion] handling completion status 0
[ 0.010174] [00001b3c] libusb: debug [disarm_timerfd] 
[ 0.010198] [00001b3c] libusb: debug [usbi_handle_transfer_completion] transfer 0x1350350 has callback 0x7ff3b72d80b0
[ 0.010222] [00001b3c] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.010251] [00001b3c] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.010284] [00001b3c] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.010308] [00001b3c] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
[ 0.010390] [00001b3c] libusb: debug [handle_events] poll() returned 1
[ 0.010417] [00001b3c] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=42
[ 0.010442] [00001b3c] libusb: debug [handle_control_completion] handling completion status 0
[ 0.010466] [00001b3c] libusb: debug [disarm_timerfd] 
[ 0.010491] [00001b3c] libusb: debug [usbi_handle_transfer_completion] transfer 0x1350350 has callback 0x7ff3b72d80b0
[ 0.010515] [00001b3c] libusb: debug [sync_transfer_cb] actual_length=42
         Serial No: "   SAMSUNG SERIAL BULK"

            length: 18
      device class: 2
               S/N: 3
           VID:PID: 04E8:685D
         bcdDevice: 0000
   iMan:iProd:iSer: 1:2:3
          nb confs: 1
[ 0.010735] [00001b3c] libusb: debug [libusb_get_config_descriptor] index 0

interface[0].altsetting[0]: num endpoints = 1
   Class.SubClass.Protocol: 02.02.01
       endpoint[0].address: 83
           max packet size: 0010
          polling interval: 09

interface[1].altsetting[0]: num endpoints = 2
   Class.SubClass.Protocol: 0A.00.00
       endpoint[0].address: 81
           max packet size: 0200
          polling interval: 00
       endpoint[1].address: 02
           max packet size: 0200
          polling interval: 00
Claiming interface...
[ 0.011081] [00001b3c] libusb: debug [libusb_claim_interface] interface 1
Setting up interface...
[ 0.011157] [00001b3c] libusb: debug [libusb_set_interface_alt_setting] interface 1 altsetting 0

Initialising protocol...
[ 0.018845] [00001b3c] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.018870] [00001b3c] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 4
[ 0.018897] [00001b3c] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.018921] [00001b3c] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
[ 0.018950] [00001b3c] libusb: debug [handle_events] poll() returned 1
[ 0.018966] [00001b3c] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=4
[ 0.018980] [00001b3c] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.018995] [00001b3c] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 0.019010] [00001b3c] libusb: debug [disarm_timerfd] 
[ 0.019024] [00001b3c] libusb: debug [usbi_handle_transfer_completion] transfer 0x1350350 has callback 0x7ff3b72d80b0
[ 0.019038] [00001b3c] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.019057] [00001b3c] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.019073] [00001b3c] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 7
[ 0.019091] [00001b3c] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.019123] [00001b3c] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms
[ 1.019170] [00001b3c] libusb: debug [handle_events] poll() returned 1
[ 1.019244] [00001b3c] libusb: debug [handle_events] timerfd triggered
[ 1.019268] [00001b3c] libusb: debug [libusb_cancel_transfer] 
[ 1.019403] [00001b3c] libusb: debug [disarm_timerfd] 
[ 1.019446] [00001b3c] libusb: debug [handle_events] poll() 4 fds with timeout in 0ms
[ 1.019465] [00001b3c] libusb: debug [handle_events] poll() returned 1
[ 1.019485] [00001b3c] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[ 1.019520] [00001b3c] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[ 1.019537] [00001b3c] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[ 1.019552] [00001b3c] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[ 1.019569] [00001b3c] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[ 1.019584] [00001b3c] libusb: debug [disarm_timerfd] 
[ 1.019599] [00001b3c] libusb: debug [usbi_handle_transfer_completion] transfer 0x1350350 has callback 0x7ff3b72d80b0
[ 1.019616] [00001b3c] libusb: debug [sync_transfer_cb] actual_length=0
ERROR: Failed to receive handshake response. Result: -7
ERROR: Protocol initialisation failed!

Releasing device interface...
[ 1.019724] [00001b3c] libusb: debug [libusb_release_interface] interface 1

[ 1.019777] [00001b3c] libusb: debug [libusb_close] 
[ 1.019806] [00001b3c] libusb: debug [usbi_remove_pollfd] remove fd 11
[ 1.019849] [00001b3c] libusb: debug [libusb_exit] 
[ 1.019881] [00001b3c] libusb: debug [libusb_exit] destroying default context

GilesBathgate avatar Jun 08 '16 18:06 GilesBathgate

It doesn't work for me either: Log here.

luis-pereira avatar Jul 19 '16 16:07 luis-pereira

Neither does it for me 
Heimdall v1.4.2

Copyright (c) 2010-2017 Benjamin Dobell, Glass Echidna
http://www.glassechidna.com.au/

This software is provided free of charge. Copying and redistribution is
encouraged.

If you appreciate this software and you would like to support future
development please consider donating:
http://www.glassechidna.com.au/donate/

Initialising connection...
Detecting device...
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.005821] [000012d6] libusb: debug [libusb_get_device_list] 
[ 0.005913] [000012d6] libusb: debug [libusb_get_device_descriptor] 
[ 0.005932] [000012d6] libusb: debug [libusb_get_device_descriptor] 
[ 0.005955] [000012d6] libusb: debug [libusb_open] open 1.6
[ 0.006030] [000012d6] libusb: debug [usbi_add_pollfd] add fd 10 events 4
[ 0.006051] [000012d6] libusb: debug [libusb_get_device_descriptor] 
[ 0.006076] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa998
[ 0.006097] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa998
[ 0.006118] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.006191] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.006217] [000012d6] libusb: debug [handle_events] poll fds modified, reallocating
[ 0.006244] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.008648] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 0.008690] [000012d6] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=4
[ 0.008710] [000012d6] libusb: debug [handle_control_completion] handling completion status 0
[ 0.008732] [000012d6] libusb: debug [disarm_timerfd] 
[ 0.008757] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa998 has callback 0xb7787c60
[ 0.008775] [000012d6] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.008812] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa998
[ 0.008842] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa998
[ 0.008861] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa998
[ 0.008990] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.009053] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.009073] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.010621] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 0.010656] [000012d6] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=16
[ 0.010676] [000012d6] libusb: debug [handle_control_completion] handling completion status 0
[ 0.010695] [000012d6] libusb: debug [disarm_timerfd] 
[ 0.010717] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa998 has callback 0xb7787c60
[ 0.010735] [000012d6] libusb: debug [sync_transfer_cb] actual_length=16
[ 0.010757] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa998
      Manufacturer: "SAMSUNG"
[ 0.010797] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa998
[ 0.010816] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa998
[ 0.010835] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.010874] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.010893] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.012612] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 0.012645] [000012d6] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=4
[ 0.012664] [000012d6] libusb: debug [handle_control_completion] handling completion status 0
[ 0.012683] [000012d6] libusb: debug [disarm_timerfd] 
[ 0.012705] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa998 has callback 0xb7787c60
[ 0.012723] [000012d6] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.012744] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa998
[ 0.012829] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa998
[ 0.012849] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa998
[ 0.012868] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.013067] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.013088] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.014620] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 0.014657] [000012d6] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=38
[ 0.014677] [000012d6] libusb: debug [handle_control_completion] handling completion status 0
[ 0.014697] [000012d6] libusb: debug [disarm_timerfd] 
[ 0.014722] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa998 has callback 0xb7787c60
[ 0.014740] [000012d6] libusb: debug [sync_transfer_cb] actual_length=38
[ 0.014763] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa998
           Product: "SAMSUNG USB DRIVER"

            length: 18
      device class: 2
               S/N: 0
           VID:PID: 04E8:685D
         bcdDevice: 021B
   iMan:iProd:iSer: 1:2:0
          nb confs: 1
[ 0.014893] [000012d6] libusb: debug [libusb_get_config_descriptor] index 0

interface[0].altsetting[0]: num endpoints = 1
   Class.SubClass.Protocol: 02.02.01
       endpoint[0].address: 83
           max packet size: 0010
          polling interval: 09

interface[1].altsetting[0]: num endpoints = 2
   Class.SubClass.Protocol: 0A.00.00
       endpoint[0].address: 81
           max packet size: 0200
          polling interval: 00
       endpoint[1].address: 02
           max packet size: 0200
          polling interval: 00
Claiming interface...
[ 0.015110] [000012d6] libusb: debug [libusb_claim_interface] interface 1
Setting up interface...
[ 0.015219] [000012d6] libusb: debug [libusb_set_interface_alt_setting] interface 1 altsetting 0

Initialising protocol...
[ 0.015687] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa998
[ 0.015709] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa998
[ 0.015729] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.015755] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 4
[ 0.015799] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.015819] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.016619] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 0.016651] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=4
[ 0.016670] [000012d6] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.016688] [000012d6] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 0.016708] [000012d6] libusb: debug [disarm_timerfd] 
[ 0.016731] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa998 has callback 0xb7787c60
[ 0.016750] [000012d6] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.016772] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa998
[ 0.016795] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa998
[ 0.016813] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa998
[ 0.016831] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[ 0.016854] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 7
[ 0.016938] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.016965] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.017614] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 0.017647] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=4
[ 0.017665] [000012d6] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.017732] [000012d6] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 0.017753] [000012d6] libusb: debug [disarm_timerfd] 
[ 0.017778] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa998 has callback 0xb7787c60
[ 0.017796] [000012d6] libusb: debug [sync_transfer_cb] actual_length=4
[ 0.017819] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa998
Protocol initialisation successful.

Beginning session...
[ 0.017907] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 0.017927] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 0.017946] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 0.017971] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 1024
[ 0.018022] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.018041] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.019607] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 0.019641] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=1024
[ 0.019660] [000012d6] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.019678] [000012d6] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 0.019696] [000012d6] libusb: debug [disarm_timerfd] 
[ 0.019720] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 0.019738] [000012d6] libusb: debug [sync_transfer_cb] actual_length=1024
[ 0.019760] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
[ 0.019783] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 0.019800] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 0.019818] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 100ms (first in line)
[ 0.019841] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 0
[ 0.019875] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.019894] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.119861] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 0.119941] [000012d6] libusb: debug [handle_events] timerfd triggered
[ 0.119964] [000012d6] libusb: debug [libusb_cancel_transfer] transfer 0x8baa808
[ 0.120389] [000012d6] libusb: debug [disarm_timerfd] 
[ 0.120422] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[ 0.120445] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 0.120469] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[ 0.120488] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[ 0.120507] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[ 0.120524] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[ 0.120543] [000012d6] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[ 0.120561] [000012d6] libusb: debug [disarm_timerfd] 
[ 0.120581] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 0.120599] [000012d6] libusb: debug [sync_transfer_cb] actual_length=0
[ 0.120624] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
WARNING: Empty bulk transfer after sending packet failed. Continuing anyway...
[ 0.120736] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 0.120755] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 0.120774] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 0.120801] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 8
[ 0.120960] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.120992] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 0.121397] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 0.121434] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=8
[ 0.121453] [000012d6] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 0.121471] [000012d6] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 0.121491] [000012d6] libusb: debug [disarm_timerfd] 
[ 0.121516] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 0.121535] [000012d6] libusb: debug [sync_transfer_cb] actual_length=8
[ 0.121558] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808

Some devices may take up to 2 minutes to respond.
Please be patient!

[ 3.121752] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 3.121896] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 3.121920] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 3.121955] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 1024
[ 3.122037] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 3.122061] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 3.123660] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.123715] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=1024
[ 3.123735] [000012d6] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 3.123754] [000012d6] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 3.123775] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.123802] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 3.123821] [000012d6] libusb: debug [sync_transfer_cb] actual_length=1024
[ 3.123846] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
[ 3.123874] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 3.123892] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 3.123910] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 100ms (first in line)
[ 3.123934] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 0
[ 3.123974] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 3.123992] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 3.224003] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.224045] [000012d6] libusb: debug [handle_events] timerfd triggered
[ 3.224065] [000012d6] libusb: debug [libusb_cancel_transfer] transfer 0x8baa808
[ 3.224388] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.224422] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[ 3.224444] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.224467] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[ 3.224486] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[ 3.224504] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[ 3.224520] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[ 3.224539] [000012d6] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[ 3.224556] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.224576] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 3.224594] [000012d6] libusb: debug [sync_transfer_cb] actual_length=0
[ 3.224617] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
WARNING: Empty bulk transfer after sending packet failed. Continuing anyway...
[ 3.224744] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 3.224766] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 3.224785] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 3.224810] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 8
[ 3.224859] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 3.224923] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 3.225397] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.225435] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=8
[ 3.225454] [000012d6] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 3.225472] [000012d6] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 3.225490] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.225515] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 3.225533] [000012d6] libusb: debug [sync_transfer_cb] actual_length=8
[ 3.225555] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
Session begun.

Downloading device's PIT file...
[ 3.225646] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 3.225664] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 3.225683] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 3.225707] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 1024
[ 3.225757] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 3.225777] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 3.227377] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.227412] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=1024
[ 3.227431] [000012d6] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 3.227449] [000012d6] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 3.227466] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.227489] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 3.227507] [000012d6] libusb: debug [sync_transfer_cb] actual_length=1024
[ 3.227528] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
[ 3.227552] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 3.227569] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 3.227587] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 100ms (first in line)
[ 3.227609] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 0
[ 3.227644] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 3.227662] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 3.327620] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.327678] [000012d6] libusb: debug [handle_events] timerfd triggered
[ 3.327698] [000012d6] libusb: debug [libusb_cancel_transfer] transfer 0x8baa808
[ 3.328153] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.328185] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[ 3.328207] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.328230] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[ 3.328249] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[ 3.328267] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[ 3.328284] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[ 3.328303] [000012d6] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[ 3.328320] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.328391] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 3.328409] [000012d6] libusb: debug [sync_transfer_cb] actual_length=0
[ 3.328433] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
WARNING: Empty bulk transfer after sending packet failed. Continuing anyway...
[ 3.328497] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 3.328515] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 3.328534] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 3.328559] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 8
[ 3.328609] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 3.328628] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 3.329164] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.329202] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=8
[ 3.329220] [000012d6] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 3.329238] [000012d6] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 3.329256] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.329279] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 3.329297] [000012d6] libusb: debug [sync_transfer_cb] actual_length=8
[ 3.329319] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
[ 3.329389] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 3.329410] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 3.329428] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 3.329452] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 1024
[ 3.329501] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 3.329520] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 3.331141] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.331175] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=1024
[ 3.331194] [000012d6] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[ 3.331212] [000012d6] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[ 3.331230] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.331252] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 3.331270] [000012d6] libusb: debug [sync_transfer_cb] actual_length=1024
[ 3.331292] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
[ 3.331315] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 3.331333] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 3.331351] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 100ms (first in line)
[ 3.331374] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 0
[ 3.331407] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 3.331426] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 3.431383] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.431429] [000012d6] libusb: debug [handle_events] timerfd triggered
[ 3.431447] [000012d6] libusb: debug [libusb_cancel_transfer] transfer 0x8baa808
[ 3.431913] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.431944] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[ 3.431967] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.431989] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[ 3.432008] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[ 3.432078] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[ 3.432096] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[ 3.432115] [000012d6] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[ 3.432133] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.432153] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 3.432171] [000012d6] libusb: debug [sync_transfer_cb] actual_length=0
[ 3.432195] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
WARNING: Empty bulk transfer after sending packet failed. Continuing anyway...
[ 3.432260] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 3.432278] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 3.432297] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 3.432321] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 500
[ 3.432369] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 3.432388] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 3.432936] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.432976] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-75 transferred=64
[ 3.432995] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -75 of bulk urb 1/1
[ 3.433013] [000012d6] libusb: debug [handle_bulk_completion] overflow, actual_length=64
[ 3.433031] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.433054] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 3.433073] [000012d6] libusb: debug [sync_transfer_cb] actual_length=64
[ 3.433094] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -8 whilst receiving bulk transfer. Retrying...
[ 3.683881] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 3.683920] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 3.683940] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 3.683966] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 500
[ 3.684009] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 3.684029] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 3.685609] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 3.685655] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-75 transferred=64
[ 3.685673] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -75 of bulk urb 1/1
[ 3.685692] [000012d6] libusb: debug [handle_bulk_completion] overflow, actual_length=64
[ 3.685710] [000012d6] libusb: debug [disarm_timerfd] 
[ 3.685735] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 3.685753] [000012d6] libusb: debug [sync_transfer_cb] actual_length=64
[ 3.685776] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -8 whilst receiving bulk transfer. Retrying...
[ 4.186493] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 4.188341] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 4.188402] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 4.188437] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 500
[ 4.188502] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 4.188524] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 4.190528] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 4.190579] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-75 transferred=64
[ 4.190598] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -75 of bulk urb 1/1
[ 4.190664] [000012d6] libusb: debug [handle_bulk_completion] overflow, actual_length=64
[ 4.190687] [000012d6] libusb: debug [disarm_timerfd] 
[ 4.190712] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 4.190730] [000012d6] libusb: debug [sync_transfer_cb] actual_length=64
[ 4.190754] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -8 whilst receiving bulk transfer. Retrying...
[ 4.941642] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 4.941787] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 4.941813] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 4.941850] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 500
[ 4.941927] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 4.941949] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 4.943413] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 4.943475] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-75 transferred=64
[ 4.943494] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -75 of bulk urb 1/1
[ 4.943513] [000012d6] libusb: debug [handle_bulk_completion] overflow, actual_length=64
[ 4.943535] [000012d6] libusb: debug [disarm_timerfd] 
[ 4.943563] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 4.943581] [000012d6] libusb: debug [sync_transfer_cb] actual_length=64
[ 4.943606] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -8 whilst receiving bulk transfer. Retrying...
[ 5.944759] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 5.944863] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 5.944906] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 5.944938] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 500
[ 5.945000] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 5.945021] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 5.946774] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 5.946816] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-75 transferred=64
[ 5.946835] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -75 of bulk urb 1/1
[ 5.946853] [000012d6] libusb: debug [handle_bulk_completion] overflow, actual_length=64
[ 5.946874] [000012d6] libusb: debug [disarm_timerfd] 
[ 5.946898] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 5.946917] [000012d6] libusb: debug [sync_transfer_cb] actual_length=64
[ 5.946940] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -8 whilst receiving bulk transfer. Retrying...
[ 7.197514] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 7.197643] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 7.197667] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 7.197701] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 500
[ 7.197771] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 7.197794] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[ 7.199078] [000012d6] libusb: debug [handle_events] poll() returned 1
[ 7.199125] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-75 transferred=64
[ 7.199144] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -75 of bulk urb 1/1
[ 7.199163] [000012d6] libusb: debug [handle_bulk_completion] overflow, actual_length=64
[ 7.199246] [000012d6] libusb: debug [disarm_timerfd] 
[ 7.199273] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[ 7.199292] [000012d6] libusb: debug [sync_transfer_cb] actual_length=64
[ 7.199317] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -8 whilst receiving bulk transfer.
ERROR: Failed to receive PIT file part #0!
ERROR: Failed to download PIT file!
Ending session...
[ 7.199466] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[ 7.199485] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[ 7.199504] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[ 7.199529] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 1024
[ 7.199581] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 7.199601] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[10.199811] [000012d6] libusb: debug [handle_events] poll() returned 1
[10.199952] [000012d6] libusb: debug [handle_events] timerfd triggered
[10.199979] [000012d6] libusb: debug [libusb_cancel_transfer] transfer 0x8baa808
[10.201073] [000012d6] libusb: debug [disarm_timerfd] 
[10.201129] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[10.201154] [000012d6] libusb: debug [handle_events] poll() returned 1
[10.201180] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[10.201199] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[10.201217] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[10.201233] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[10.201253] [000012d6] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[10.201271] [000012d6] libusb: debug [disarm_timerfd] 
[10.201291] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[10.201309] [000012d6] libusb: debug [sync_transfer_cb] actual_length=0
[10.201336] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -7 whilst sending bulk transfer. Retrying...
[10.451560] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[10.451606] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[10.451626] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[10.451652] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 1024
[10.451718] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[10.451739] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[13.451813] [000012d6] libusb: debug [handle_events] poll() returned 1
[13.451951] [000012d6] libusb: debug [handle_events] timerfd triggered
[13.451975] [000012d6] libusb: debug [libusb_cancel_transfer] transfer 0x8baa808
[13.453744] [000012d6] libusb: debug [disarm_timerfd] 
[13.453787] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[13.453811] [000012d6] libusb: debug [handle_events] poll() returned 1
[13.453839] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[13.453857] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[13.453876] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[13.453892] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[13.453913] [000012d6] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[13.453931] [000012d6] libusb: debug [disarm_timerfd] 
[13.453951] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[13.453969] [000012d6] libusb: debug [sync_transfer_cb] actual_length=0
[13.454060] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -7 whilst sending bulk transfer. Retrying...
[13.954814] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[13.954859] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[13.954880] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[13.954908] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 1024
[13.954977] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[13.954997] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[16.955058] [000012d6] libusb: debug [handle_events] poll() returned 1
[16.955217] [000012d6] libusb: debug [handle_events] timerfd triggered
[16.955244] [000012d6] libusb: debug [libusb_cancel_transfer] transfer 0x8baa808
[16.956789] [000012d6] libusb: debug [disarm_timerfd] 
[16.956839] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[16.956864] [000012d6] libusb: debug [handle_events] poll() returned 1
[16.956961] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[16.956982] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[16.957001] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[16.957018] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[16.957038] [000012d6] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[16.957056] [000012d6] libusb: debug [disarm_timerfd] 
[16.957077] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[16.957096] [000012d6] libusb: debug [sync_transfer_cb] actual_length=0
[16.957122] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -7 whilst sending bulk transfer. Retrying...
[17.707290] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[17.707392] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[17.707414] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[17.707443] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 1024
[17.707514] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[17.707535] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[20.707495] [000012d6] libusb: debug [handle_events] poll() returned 1
[20.707623] [000012d6] libusb: debug [handle_events] timerfd triggered
[20.707647] [000012d6] libusb: debug [libusb_cancel_transfer] transfer 0x8baa808
[20.709050] [000012d6] libusb: debug [disarm_timerfd] 
[20.709088] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[20.709112] [000012d6] libusb: debug [handle_events] poll() returned 1
[20.709138] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[20.709157] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[20.709175] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[20.709191] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[20.709211] [000012d6] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[20.709229] [000012d6] libusb: debug [disarm_timerfd] 
[20.709249] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[20.709267] [000012d6] libusb: debug [sync_transfer_cb] actual_length=0
[20.709293] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -7 whilst sending bulk transfer. Retrying...
[21.709500] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[21.709611] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[21.709683] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[21.709716] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 1024
[21.709788] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[21.709809] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[24.709787] [000012d6] libusb: debug [handle_events] poll() returned 1
[24.709910] [000012d6] libusb: debug [handle_events] timerfd triggered
[24.709933] [000012d6] libusb: debug [libusb_cancel_transfer] transfer 0x8baa808
[24.711129] [000012d6] libusb: debug [disarm_timerfd] 
[24.711165] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[24.711189] [000012d6] libusb: debug [handle_events] poll() returned 1
[24.711214] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[24.711232] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[24.711251] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[24.711267] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[24.711287] [000012d6] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[24.711305] [000012d6] libusb: debug [disarm_timerfd] 
[24.711325] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[24.711343] [000012d6] libusb: debug [sync_transfer_cb] actual_length=0
[24.711368] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -7 whilst sending bulk transfer. Retrying...
[25.961599] [000012d6] libusb: debug [libusb_alloc_transfer] transfer 0x8baa808
[25.961725] [000012d6] libusb: debug [libusb_submit_transfer] transfer 0x8baa808
[25.961747] [000012d6] libusb: debug [add_to_flying_list] arm timerfd for timeout in 3000ms (first in line)
[25.961780] [000012d6] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 1024
[25.961854] [000012d6] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[25.961875] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 60000ms
[28.961871] [000012d6] libusb: debug [handle_events] poll() returned 1
[28.961997] [000012d6] libusb: debug [handle_events] timerfd triggered
[28.962020] [000012d6] libusb: debug [libusb_cancel_transfer] transfer 0x8baa808
[28.963553] [000012d6] libusb: debug [disarm_timerfd] 
[28.963589] [000012d6] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[28.963613] [000012d6] libusb: debug [handle_events] poll() returned 1
[28.963638] [000012d6] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0
[28.963657] [000012d6] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[28.963675] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[28.963692] [000012d6] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[28.963711] [000012d6] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation
[28.963729] [000012d6] libusb: debug [disarm_timerfd] 
[28.963749] [000012d6] libusb: debug [usbi_handle_transfer_completion] transfer 0x8baa808 has callback 0xb7787c60
[28.963767] [000012d6] libusb: debug [sync_transfer_cb] actual_length=0
[28.963792] [000012d6] libusb: debug [libusb_free_transfer] transfer 0x8baa808
ERROR: libusb error -7 whilst sending bulk transfer.
ERROR: Failed to send end session packet!
Releasing device interface...
[28.963909] [000012d6] libusb: debug [libusb_release_interface] interface 1

[28.963987] [000012d6] libusb: debug [libusb_close] 
[28.964017] [000012d6] libusb: debug [usbi_remove_pollfd] remove fd 10
[28.964062] [000012d6] libusb: debug [libusb_exit] 
[28.964079] [000012d6] libusb: debug [libusb_exit] destroying default context

KOLANICH avatar Jul 09 '17 12:07 KOLANICH

This patch worked for me to fix USB issues with Galaxy Tab S2 (Samsung SM-T813) on Ubuntu 16.04 LTS. Log is here.

procrastinat0r avatar Mar 21 '18 10:03 procrastinat0r

@procrastinat0r could you share the pcap dump?

KOLANICH avatar Mar 21 '18 10:03 KOLANICH

SGS5 g900t user here. This patch changes nothing of the behavior for me on the S5. still get ERROR: Failed to receive handshake response. Result: -7

Heimdall v1.4.2

Copyright (c) 2010-2017 Benjamin Dobell, Glass Echidna http://www.glassechidna.com.au/

This software is provided free of charge. Copying and redistribution is encouraged.

If you appreciate this software and you would like to support future development please consider donating: http://www.glassechidna.com.au/donate/

Initialising connection... Detecting device... [timestamp] [threadID] facility level [function call]

[ 0.012848] [00004528] libusb: debug [libusb_get_device_list] [ 0.012861] [00004528] libusb: debug [discovered_devs_append] need to increase capacity [ 0.012865] [00004528] libusb: debug [libusb_get_device_descriptor] [ 0.012867] [00004528] libusb: debug [libusb_get_device_descriptor] [ 0.012868] [00004528] libusb: debug [libusb_get_device_descriptor] [ 0.012870] [00004528] libusb: debug [libusb_get_device_descriptor] [ 0.012871] [00004528] libusb: debug [libusb_get_device_descriptor] [ 0.012872] [00004528] libusb: debug [libusb_get_device_descriptor] [ 0.012873] [00004528] libusb: debug [libusb_get_device_descriptor] [ 0.012875] [00004528] libusb: debug [libusb_get_device_descriptor] [ 0.012876] [00004528] libusb: debug [libusb_get_device_descriptor] [ 0.012879] [00004528] libusb: debug [libusb_open] open 1.51 [ 0.012893] [00004528] libusb: debug [usbi_add_pollfd] add fd 11 events 4 [ 0.012900] [00004528] libusb: debug [libusb_get_device_descriptor] [ 0.012904] [00004528] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line) [ 0.012917] [00004528] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling [ 0.012919] [00004528] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms [ 0.013005] [00004528] libusb: debug [handle_events] poll() returned 1 [ 0.013013] [00004528] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=4 [ 0.013015] [00004528] libusb: debug [handle_control_completion] handling completion status 0 [ 0.013017] [00004528] libusb: debug [disarm_timerfd] [ 0.013019] [00004528] libusb: debug [usbi_handle_transfer_completion] transfer 0x147f0f0 has callback 0x7fa37c28d1d0 [ 0.013021] [00004528] libusb: debug [sync_transfer_cb] actual_length=4 [ 0.013029] [00004528] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line) [ 0.013034] [00004528] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling [ 0.013036] [00004528] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms [ 0.013125] [00004528] libusb: debug [handle_events] poll() returned 1 [ 0.013133] [00004528] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=18 [ 0.013135] [00004528] libusb: debug [handle_control_completion] handling completion status 0 [ 0.013136] [00004528] libusb: debug [disarm_timerfd] [ 0.013138] [00004528] libusb: debug [usbi_handle_transfer_completion] transfer 0x147f0f0 has callback 0x7fa37c28d1d0 [ 0.013140] [00004528] libusb: debug [sync_transfer_cb] actual_length=18 Manufacturer: "Sasmsung" [ 0.013145] [00004528] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line) [ 0.013150] [00004528] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling [ 0.013152] [00004528] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms [ 0.013239] [00004528] libusb: debug [handle_events] poll() returned 1 [ 0.013247] [00004528] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=4 [ 0.013249] [00004528] libusb: debug [handle_control_completion] handling completion status 0 [ 0.013251] [00004528] libusb: debug [disarm_timerfd] [ 0.013252] [00004528] libusb: debug [usbi_handle_transfer_completion] transfer 0x147f0f0 has callback 0x7fa37c28d1d0 [ 0.013254] [00004528] libusb: debug [sync_transfer_cb] actual_length=4 [ 0.013258] [00004528] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line) [ 0.013265] [00004528] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling [ 0.013267] [00004528] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms [ 0.013354] [00004528] libusb: debug [handle_events] poll() returned 1 [ 0.013361] [00004528] libusb: debug [reap_for_handle] urb type=2 status=0 transferred=16 [ 0.013363] [00004528] libusb: debug [handle_control_completion] handling completion status 0 [ 0.013365] [00004528] libusb: debug [disarm_timerfd] [ 0.013367] [00004528] libusb: debug [usbi_handle_transfer_completion] transfer 0x147f0f0 has callback 0x7fa37c28d1d0 [ 0.013368] [00004528] libusb: debug [sync_transfer_cb] actual_length=16 Product: "MSM8960"

        length: 18
  device class: 2
           S/N: 0
       VID:PID: 04E8:685D
     bcdDevice: 0100

iMan:iProd:iSer: 1:2:0 nb confs: 1 [ 0.013380] [00004528] libusb: debug [libusb_get_config_descriptor] index 0

interface[0].altsetting[0]: num endpoints = 1 Class.SubClass.Protocol: 02.02.01 endpoint[0].address: 82 max packet size: 0010 polling interval: 09

interface[1].altsetting[0]: num endpoints = 2 Class.SubClass.Protocol: 0A.00.00 endpoint[0].address: 81 max packet size: 0200 polling interval: 00 endpoint[1].address: 01 max packet size: 0200 polling interval: 00 Claiming interface... [ 0.013397] [00004528] libusb: debug [libusb_claim_interface] interface 1 Setting up interface... [ 0.013413] [00004528] libusb: debug [libusb_set_interface_alt_setting] interface 1 altsetting 0

Initialising protocol... [ 0.013767] [00004528] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line) [ 0.013773] [00004528] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 4 [ 0.013779] [00004528] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling [ 0.013781] [00004528] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms [ 0.013790] [00004528] libusb: debug [handle_events] poll() returned 1 [ 0.013793] [00004528] libusb: debug [reap_for_handle] urb type=3 status=0 transferred=4 [ 0.013795] [00004528] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1 [ 0.013796] [00004528] libusb: debug [handle_bulk_completion] last URB in transfer --> complete! [ 0.013798] [00004528] libusb: debug [disarm_timerfd] [ 0.013800] [00004528] libusb: debug [usbi_handle_transfer_completion] transfer 0x147f120 has callback 0x7fa37c28d1d0 [ 0.013801] [00004528] libusb: debug [sync_transfer_cb] actual_length=4 [ 0.013804] [00004528] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line) [ 0.013806] [00004528] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 7 [ 0.013809] [00004528] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling [ 0.013811] [00004528] libusb: debug [handle_events] poll() 4 fds with timeout in 60000ms [ 1.013828] [00004528] libusb: debug [handle_events] poll() returned 1 [ 1.013840] [00004528] libusb: debug [handle_events] timerfd triggered [ 1.013844] [00004528] libusb: debug [libusb_cancel_transfer] [ 1.013889] [00004528] libusb: debug [disarm_timerfd] [ 1.013898] [00004528] libusb: debug [handle_events] poll() 4 fds with timeout in 0ms [ 1.013902] [00004528] libusb: debug [handle_events] poll() returned 1 [ 1.013907] [00004528] libusb: debug [reap_for_handle] urb type=3 status=-2 transferred=0 [ 1.013909] [00004528] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1 [ 1.013911] [00004528] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2 [ 1.013912] [00004528] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting [ 1.013914] [00004528] libusb: debug [usbi_handle_transfer_cancellation] detected timeout cancellation [ 1.013916] [00004528] libusb: debug [disarm_timerfd] [ 1.013918] [00004528] libusb: debug [usbi_handle_transfer_completion] transfer 0x147f120 has callback 0x7fa37c28d1d0 [ 1.013919] [00004528] libusb: debug [sync_transfer_cb] actual_length=0 ERROR: Failed to receive handshake response. Result: -7 ERROR: Failed to receive handshake response. Result: -7 ERROR: Protocol initialisation failed!

ERROR: Protocol initialisation failed!

Releasing device interface... [ 1.013937] [00004528] libusb: debug [libusb_release_interface] interface 1

[ 1.013951] [00004528] libusb: debug [libusb_close] [ 1.013956] [00004528] libusb: debug [usbi_remove_pollfd] remove fd 11 [ 1.013961] [00004528] libusb: debug [libusb_exit] [ 1.013962] [00004528] libusb: debug [libusb_exit] destroying default context

sanimalp avatar Apr 11 '18 20:04 sanimalp

@sanimalp 1 could you hide the log under <details> tag? 2 without pcap captures it's pretty useless

KOLANICH avatar Apr 11 '18 20:04 KOLANICH

I found that this patch plus one other change seemed to work for me. Specifically, within BridgeManager::InitialiseProtocol() I had to change the timeout for the "ODIN" message from 1000 to 6000. After that, it appears to work on my machine on either USB2 or USB3. Machine is Intel i7-6700 @ 3.40 GHz running Fedora 34 (kernel 5.14.14-200).

beroset avatar Nov 24 '21 22:11 beroset

That sounds great, @beroset! I am thinking about merging this in my fork. Which was the other change that you needed for heimdall to work with your device? What was the error you were getting before? And what device do you have?

amo13 avatar Nov 25 '21 05:11 amo13

@amo13 The device is a Samsung Galaxy Tab 4 (Model SM-T230NU, Android version 4.4.2). The error I was originally getting was this:

Initialising protocol...
ERROR: libusb error -7 (LIBUSB_ERROR_TIMEOUT) whilst sending bulk transfer. Retrying...
ERROR: libusb error -7 (LIBUSB_ERROR_TIMEOUT) whilst sending bulk transfer. Retrying...
ERROR: libusb error -7 (LIBUSB_ERROR_TIMEOUT) whilst sending bulk transfer. Retrying...
ERROR: libusb error -7 (LIBUSB_ERROR_TIMEOUT) whilst sending bulk transfer. Retrying...
ERROR: libusb error -7 (LIBUSB_ERROR_TIMEOUT) whilst sending bulk transfer. Retrying...
ERROR: libusb error -7 (LIBUSB_ERROR_TIMEOUT) whilst sending bulk transfer.
ERROR: Failed to send handshake!ERROR: Failed to receive handshake response. Result: -7
ERROR: Protocol initialisation failed!

(I added the part to translate the -7 into something a little more human readable.) In addition to changing the timeout for the ODIN message as mentioned above, I also found that I needed to modify the code to try twice to send the EndSessionPacket. It was able to flash both a RECOVERY and CACHE image but would fail on parsing the reply to that. Trying twice allowed it to finish the job and reboot. After I clean up my code a bit, I'll create a fork and a pull request.

beroset avatar Nov 25 '21 05:11 beroset

After I clean up my code a bit, I'll create a fork and a pull request.

That would be awesome!

Thanks for the hints. Why the need to flash a CACHE image though?

amo13 avatar Nov 25 '21 06:11 amo13

I have done some more thorough testing and believe that the problem is not timeouts at all. Specifically, I have determined with two Linux machines that I have, if I reset the Samsung tablet into ODIN mode and execute sudo heimdall print-pit --verbose --no-reboot --usb-log-level debug it works perfectly the first time regardless of timeout settings. The second time I execute the same command, I get errors. It seems that the tablet is left in a state that makes it unwilling to further communicate, but why? What's missing?

beroset avatar Nov 25 '21 20:11 beroset

Oh, I have come across this issue quite a few times with a few different devices. I believe it is also somewhat known and you'll read about other users reporting this behavior in some other issues on here... Still, in my experience of flashing samsung devices with heimdall, even though I have seen this behavior a few times, most devices will also accept further commands. As for why this is happening, unfortunately, I have no idea either. My only guess is that the --no-reboot flag somehow tricks the protocol that is not made to accept multiple commands.

amo13 avatar Nov 26 '21 07:11 amo13

I too was suffering with the "ERROR: libusb error -7 whilst sending bulk transfer." issue on my Samsung s5e WIFI.

This patch alone did not seem to make any difference, but as soon as I tried @amo13 fork mentioned above then it started working perfectly :)

Thanks everyone!

bobemoe avatar Jan 14 '22 08:01 bobemoe