JeffLIrion / adb_shell

A Python implementation of ADB with shell and FileSync functionality.
Apache License 2.0
543 stars 60 forks source link

Pushing large files always timeouts #205

Open sharpordie opened 2 years ago

sharpordie commented 2 years ago

I am trying to push 30Mo+ file to my Nvidia Shield device.

It works with small text files but not with bigger ones.

import logging
from os import getcwd
from os.path import abspath, basename, dirname, exists, join

from adb_shell.adb_device import AdbDeviceTcp
from adb_shell.auth.keygen import keygen
from adb_shell.auth.sign_pythonrsa import PythonRSASigner

logging.basicConfig(level=logging.INFO)

def main():
    pvt_key = join(dirname(abspath(__file__)), "adbkey")
    pub_key = pvt_key + ".pub"
    if not exists(pvt_key):
        keygen(pvt_key)
    with open(pub_key) as f:
        pub_bin = f.read()
    with open(pvt_key) as f:
        pvt_bin = f.read()
    manager = AdbDeviceTcp("192.168.1.62")
    manager.connect(rsa_keys=[PythonRSASigner(pub_bin, pvt_bin)], auth_timeout_s=0.1)
    package = join(getcwd(), "package.apk")
    deposit = join("/sdcard", basename(package))
    manager.push(package, deposit, progress_callback=callback)

def callback(device_path, bytes_written, total_bytes):
    logging.info(f"Progress: {device_path} written:{bytes_written} total:{total_bytes}")

main()

This is what I get from the logger, it seems to be blocked at 65536 bytes.

INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453
INFO:root:Progress: /sdcard/package.apk written:65536 total:83586453

And there is the traceback.

Traceback (most recent call last):
  File "/home/lan/Documents/demo/test.py", line 34, in <module>
    main()
  File "/home/lan/Documents/demo/test.py", line 27, in main
    manager.push(package, deposit, progress_callback=callback)
  File "/home/lan/.local/lib/python3.10/site-packages/adb_shell/adb_device.py", line 1017, in push
    self._push(stream, _device_path, st_mode, mtime, progress_callback, adb_info, filesync_info)
  File "/home/lan/.local/lib/python3.10/site-packages/adb_shell/adb_device.py", line 1055, in _push
    self._filesync_send(constants.DATA, adb_info, filesync_info, data=data)
  File "/home/lan/.local/lib/python3.10/site-packages/adb_shell/adb_device.py", line 1467, in _filesync_send
    self._filesync_flush(adb_info, filesync_info)
  File "/home/lan/.local/lib/python3.10/site-packages/adb_shell/adb_device.py", line 1314, in _filesync_flush
    self._read_until([constants.OKAY], adb_info)
  File "/home/lan/.local/lib/python3.10/site-packages/adb_shell/adb_device.py", line 1213, in _read_until
    cmd, _, _, data = self._io_manager.read(expected_cmds, adb_info, allow_zeros=True)
  File "/home/lan/.local/lib/python3.10/site-packages/adb_shell/adb_device.py", line 339, in read
    cmd, arg0, arg1, data = self._read_packet_from_device(adb_info)
  File "/home/lan/.local/lib/python3.10/site-packages/adb_shell/adb_device.py", line 486, in _read_packet_from_device
    msg = self._read_bytes_from_device(constants.MESSAGE_SIZE, adb_info)
  File "/home/lan/.local/lib/python3.10/site-packages/adb_shell/adb_device.py", line 442, in _read_bytes_from_device
    temp = self._transport.bulk_read(length, adb_info.transport_timeout_s)
  File "/home/lan/.local/lib/python3.10/site-packages/adb_shell/transport/tcp_transport.py", line 120, in bulk_read
    raise TcpTimeoutException(msg)
adb_shell.exceptions.TcpTimeoutException: Reading from 192.168.1.62:5555 timed out (10.0 seconds)

Adjusting the read_timeout_s or transport_timeout_s doesn't help.

sharpordie commented 2 years ago

I just tried the async way and it works.

from asyncio import run
from os.path import abspath, basename, dirname, exists, join
from os import getcwd

from adb_shell.adb_device_async import AdbDeviceTcpAsync
from adb_shell.auth.keygen import keygen
from adb_shell.auth.sign_pythonrsa import PythonRSASigner

async def main():
    pvt_key = join(dirname(abspath(__file__)), "adbkey")
    pub_key = pvt_key + ".pub"
    if not exists(pvt_key):
        keygen(pvt_key)
    with open(pub_key) as f:
        pub_bin = f.read()
    with open(pvt_key) as f:
        pvt_bin = f.read()
    manager = AdbDeviceTcpAsync("192.168.1.62")
    await manager.connect(rsa_keys=[PythonRSASigner(pub_bin, pvt_bin)], auth_timeout_s=0.1)
    package = join(getcwd(), "package.apk")
    deposit = join("/sdcard", basename(package))
    await manager.push(package, deposit)

run(main())
JeffLIrion commented 2 years ago

That's strange that it works with the async version but not the sync version.

The progress callback parameter is the number of bytes written at that iteration, not the total number. That's not very clear and should probably be fixed. https://github.com/JeffLIrion/adb_shell/blob/2b560d212d234f87f427dfb194a73ac1a9628b42/adb_shell/adb_device.py#L1053-L1059

sharpordie commented 2 years ago

Is there something wrong with my synchronous code? I tested on different "platforms" and with different python versions and it always timeouts even if I increase the read_timeout_s. What is the version you use in your tests?

However I'm really considering rewriting all my code to make it async friendly so your package is awesome ;)

JeffLIrion commented 2 years ago

I didn't see anything wrong with your code. After all, it works for a little while before it fails. It looks to me like the problem is in the TcpTransport class, either with the socket code or the use of select(). But I'm not an expert with either of those.

wimmatthijs commented 1 year ago

Unfortunately i'm also in the case where it doesn't work. I did rewrite my program as async but still no luck. Eventually i copied @sharpordie's async sample and tried to execute this but again, the timeout remains.

python testscript.py
Traceback (most recent call last):
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\asyncio\streams.py", line 669, in read
    await self._wait_for_data('read')
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\asyncio\streams.py", line 502, in _wait_for_data
    await self._waiter
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\asyncio\tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\transport\tcp_transport_async.py", line 103, in bulk_read
    return await asyncio.wait_for(self._reader.read(numbytes), transport_timeout_s)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\asyncio\tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "C:\i3QA_Logging_ALlsync\testscript.py", line 26, in <module>
    run(main())
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\asyncio\runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\asyncio\base_events.py", line 646, in run_until_complete
    return future.result()
  File "C:\i3QA_Logging_ALlsync\testscript.py", line 23, in main
    await manager.push(package, deposit)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\adb_device_async.py", line 1056, in push
    await self._push(stream, _device_path, st_mode, mtime, progress_callback, adb_info, filesync_info)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\adb_device_async.py", line 1109, in _push
    async for cmd_id, _, data in self._filesync_read_until([], [constants.OKAY, constants.FAIL], adb_info, filesync_info):
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\adb_device_async.py", line 1472, in _filesync_read_until
    cmd_id, header, data = await self._filesync_read(expected_ids + finish_ids, adb_info, filesync_info)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\adb_device_async.py", line 1391, in _filesync_read
    header_data = await self._filesync_read_buffered(filesync_info.recv_message_size, adb_info, filesync_info)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\adb_device_async.py", line 1440, in _filesync_read_buffered
    _, data = await self._read_until([constants.WRTE], adb_info)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\adb_device_async.py", line 1252, in _read_until
    cmd, _, _, data = await self._io_manager.read(expected_cmds, adb_info, allow_zeros=True)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\adb_device_async.py", line 376, in read
    cmd, arg0, arg1, data = await self._read_packet_from_device(adb_info)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\adb_device_async.py", line 523, in _read_packet_from_device
    msg = await self._read_bytes_from_device(constants.MESSAGE_SIZE, adb_info)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\adb_device_async.py", line 479, in _read_bytes_from_device
    temp = await self._transport.bulk_read(length, adb_info.transport_timeout_s)
  File "C:\Users\Wim.Matthijs\AppData\Local\Programs\Python\Python310\lib\site-packages\adb_shell\transport\tcp_transport_async.py", line 106, in bulk_read
    raise TcpTimeoutException(msg) from exc
adb_shell.exceptions.TcpTimeoutException: Reading from 10.10.20.38:5555 timed out (10.0 seconds)
wimmatthijs commented 1 year ago

In my case i got it to work, for me the error was that i presumed the push command would be possible to a folder destination instead a fully qualified destination with filename, similar to the adb push command. As soon as i changed this both, async and sync push commands worked. My targets are android 13, 11 and 8 devices

TheZ3ro commented 1 year ago

@wimmatthijs can you share your testscript.py file ?

I think we can catch this type of use-case and either change its behavior to support folder destinations or report better to the user that the function need a fully qualified destination instead of hanging to timeout.

wimmatthijs commented 1 year ago

@TheZ3ro it is for my workaround for the missing install command cfr. the android adb command "adb install" I now created a function which will just push the apk in file to the sdcard folder and install from there. This function is in my class, an externsion class for our purposes to AdbDeviceTcpAsync

As you can see, i'm still seeing the timeout quite regularly (about 2-3% of cases) so i'm catching it. Most of the times the command executed succesfully on the device end, but comms timed out for some reason....

    async def install(self, apk):
        if self.available:
            try:
                print('pushing ' + apk + ' to ' + self.name)
                await self.push(apk, "/sdcard/" + apk)
                print('installing ' + apk + ' on ' + self.name + '...')
                # added -r option for some devices not willing to install
                print(self.name + ' ' + await self.shell("pm install -r /sdcard/" + apk))
            except exceptions.TcpTimeoutException:
                print("Installation timed out for " + self.name)
                print("It could have dropped communications during install, verify install manually")
            except:
                print("Installation failed for " + self.name)
wimmatthijs commented 1 year ago

@TheZ3ro After some testing, here is some additional information. In my fleet the commands only time out when the target is running android 8.0, however the app installs correctly, so i reckon the shelled pm install instruction response times out. In that sense we might not be on the original topic anymore which i think is resolved by using the fully qualified path. For android 11 and 13 test devices there are no issues. This is reproducible.

arist0v commented 1 year ago

I'm currently facing the same issue here is the information:

i could provide more information if needed

arist0v commented 1 year ago

what i currently found:

performing an ls on the foler a try to work on, it seem i don't' have permission, so if you're facing timeout issue, try to ls the destination folder to make sure you have the right

edit: suggestion: maybe add a checkup to see if we could acces the folder(ls command or something else) and raise an error if permissino denied

barkside commented 1 year ago

I'm also finding sync fails for large files, but works for async. I'm on ubuntu 22 if that makes a difference