ADB Push fails: "Unable to unpack ADB command"

[7homasSutter]

Hi there,

I was trying to push some files to the newest Android Emulator (stable v.30.2.5 x86_64) but the push command fails after sending '983040' bytes with a "Unable to unpack ADB command" (see Log 1). In another attempt I tried to send a file which is smaller than the '983040' bytes but the same error occurs (see Log 2) and from the progress log it seems like too many bytes were sent.

From the exception I can see that the error is raised in adb_message.py on Line 122 in the unpack method. Could it be that there is some new adb message which is not yet supported or something like that? Or has anyone an idea what's causing this error?

Thx for any help

Tom

Log 1

worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_write: b'CNXN\x00\x00\x00\x01\x00\x00\x10\x00\x13\x00\x00\x00a\x05\x00\x00\xbc\xb1\xa7\xb1'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_write: b'host::eb22059493bd\x00'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_read(24): b'CNXN\x01\x00\x00\x01\x00\x00\x10\x00\x10\x01\x00\x00\xa1f\x00\x00\xbc\xb1\xa7\xb1'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_read(272): b'device::ro.product.name=sdk_gphone_x86_64_arm64;ro.product.model=sdk_gphone_x86_64_arm64;ro.product.device=generic_x86_64_arm64;features=sendrecv_v2_brotli,remount_shell,sendrecv_v2,abb_exec,fixed_push_mkdir,fixed_push_symlink_timestamp,abb,shell_v2,cmd,ls_v2,apex,stat_v2'
worker-low           | 2020-11-16 07:06:51 INFO     ADB device xxx:5555 is connected: True
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xfe\x01\x00\x00\xb0\xaf\xba\xb1'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_write: b'root:\x00'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_read(24): b'OKAYj\x06\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_read(24): b'WRTEj\x06\x00\x00\x01\x00\x00\x00 \x00\x00\x00\x8c\x0b\x00\x00\xa8\xad\xab\xba'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_read(32): b'adbd is already running as root\n'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00j\x06\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_read(24): b'CLSEj\x06\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00j\x06\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
worker-low           | 2020-11-16 07:06:51 INFO     local_path: ./file_store/00_file_storage/libs/frida-server-14.0.8-android-x86_64
worker-low           | 2020-11-16 07:06:51 INFO     device_path: /data/local/tmp/frida-server-14.0.8-android-x86_64
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xf7\x01\x00\x00\xb0\xaf\xba\xb1'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_write: b'sync:\x00'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_read(24): b'CLSEj\x06\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_read(24): b'OKAYk\x06\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:65536 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:131072 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:196608 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:262144 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:327680 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:393216 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:458752 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:524288 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:589824 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:655360 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:720896 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:786432 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:851968 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:917504 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-x86_64 bytes_written:983040 total_bytes:29902472
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_write: b'WRTE\x01\x00\x00\x00k\x06\x00\x00\xb8\x00\x0f\x00\xba\xa5x\x05\xa8\xad\xab\xba'
worker-low           | 2020-11-16 07:06:51 DEBUG    bulk_write: bytearray(b'SEND8\x00\x00\x00/data/local/tmp/frida-server-14.0.8-android-x86_64,33272DAT...<ENDLESS NUMBER OF HEX BYTES>...\x00\x00\x00\x89t$0PW\xe8\xf1\xef\xff\xff\x83\xc4\x0c\x8b|$\x08W\xb8$\x00\x00\x00PP\xe8\xdd\xef\xff')

And then after some time this error occurres:

worker-low           | 2020-11-16 07:11:54 DEBUG    bulk_read(24): b''
worker-low           | 07:11:54 Traceback (most recent call last):
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_message.py", line 120, in unpack
worker-low           |     cmd, arg0, arg1, data_length, data_checksum, _ = struct.unpack(constants.MESSAGE_FORMAT, message)
worker-low           | struct.error: unpack requires a buffer of 24 bytes
worker-low           | 
worker-low           | During handling of the above exception, another exception occurred:
worker-low           | 
worker-low           | Traceback (most recent call last):
worker-low           |   File "/usr/local/lib/python3.7/site-packages/rq/worker.py", line 936, in perform_job
worker-low           |     rv = job.perform()
worker-low           |   File "/usr/local/lib/python3.7/site-packages/rq/job.py", line 684, in perform
worker-low           |     self._result = self._execute()
worker-low           |   File "/usr/local/lib/python3.7/site-packages/rq/job.py", line 690, in _execute
worker-low           |     return self.func(*self.args, **self.kwargs)
worker-low           |   File "./scripts/dynamic_analysis/emulator_control/emulator_runner.py", line 21, in start_dynamic_analysis
worker-low           |     install_frida_server(adb_device)
worker-low           |   File "./scripts/dynamic_analysis/frida/frida_server_installer.py", line 17, in install_frida_server
worker-low           |     push_file(adb_device, local_path, device_path)
worker-low           |   File "./scripts/dynamic_analysis/emulator_control/adb/adb_wrapper.py", line 64, in push_file
worker-low           |     read_timeout_s=600)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 551, in push
worker-low           |     self._push(stream, _device_path, st_mode, mtime, progress_callback, adb_info, filesync_info)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 591, in _push
worker-low           |     self._filesync_send(constants.DATA, adb_info, filesync_info, data=data)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 1111, in _filesync_send
worker-low           |     self._filesync_flush(adb_info, filesync_info)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 963, in _filesync_flush
worker-low           |     self._write(filesync_info.send_buffer[:filesync_info.send_idx], adb_info)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 945, in _write
worker-low           |     self._read_until([constants.OKAY], adb_info)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 819, in _read_until
worker-low           |     cmd, remote_id2, local_id2, data = self._read(expected_cmds, adb_info)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 754, in _read
worker-low           |     cmd, arg0, arg1, data_length, data_checksum = unpack(msg)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_message.py", line 122, in unpack
worker-low           |     raise ValueError('Unable to unpack ADB command. (length={})'.format(len(message)), constants.MESSAGE_FORMAT, message, e)
worker-low           | ValueError: ('Unable to unpack ADB command. (length=0)', b'<6I', b'', error('unpack requires a buffer of 24 bytes'))
worker-low           | Traceback (most recent call last):
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_message.py", line 120, in unpack
worker-low           |     cmd, arg0, arg1, data_length, data_checksum, _ = struct.unpack(constants.MESSAGE_FORMAT, message)
worker-low           | struct.error: unpack requires a buffer of 24 bytes

worker-low           | Traceback (most recent call last):
worker-low           |   File "/usr/local/lib/python3.7/site-packages/rq/worker.py", line 936, in perform_job
worker-low           |     rv = job.perform()
worker-low           |   File "/usr/local/lib/python3.7/site-packages/rq/job.py", line 684, in perform
worker-low           |     self._result = self._execute()
worker-low           |   File "/usr/local/lib/python3.7/site-packages/rq/job.py", line 690, in _execute
worker-low           |     return self.func(*self.args, **self.kwargs)
worker-low           |   File "./scripts/dynamic_analysis/emulator_control/emulator_runner.py", line 21, in start_dynamic_analysis
worker-low           |     install_frida_server(adb_device)
worker-low           |   File "./scripts/dynamic_analysis/frida/frida_server_installer.py", line 17, in install_frida_server
worker-low           |     push_file(adb_device, local_path, device_path)
worker-low           |   File "./scripts/dynamic_analysis/emulator_control/adb/adb_wrapper.py", line 64, in push_file
worker-low           |     read_timeout_s=600)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 551, in push
worker-low           |     self._push(stream, _device_path, st_mode, mtime, progress_callback, adb_info, filesync_info)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 591, in _push
worker-low           |     self._filesync_send(constants.DATA, adb_info, filesync_info, data=data)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 1111, in _filesync_send
worker-low           |     self._filesync_flush(adb_info, filesync_info)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 963, in _filesync_flush
worker-low           |     self._write(filesync_info.send_buffer[:filesync_info.send_idx], adb_info)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 945, in _write
worker-low           |     self._read_until([constants.OKAY], adb_info)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 819, in _read_until
worker-low           |     cmd, remote_id2, local_id2, data = self._read(expected_cmds, adb_info)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_device.py", line 754, in _read
worker-low           |     cmd, arg0, arg1, data_length, data_checksum = unpack(msg)
worker-low           |   File "/usr/local/lib/python3.7/site-packages/adb_shell/adb_message.py", line 122, in unpack
worker-low           |     raise ValueError('Unable to unpack ADB command. (length={})'.format(len(message)), constants.MESSAGE_FORMAT, message, e)
worker-low           | ValueError: ('Unable to unpack ADB command. (length=0)', b'<6I', b'', error('unpack requires a buffer of 24 bytes'))

Log 2

worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_write: b'CNXN\x00\x00\x00\x01\x00\x00\x10\x00\x13\x00\x00\x00l\x05\x00\x00\xbc\xb1\xa7\xb1'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_write: b'host::ff918e63b615\x00'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_read(24): b'CNXN\x01\x00\x00\x01\x00\x00\x10\x00\x10\x01\x00\x00\xa1f\x00\x00\xbc\xb1\xa7\xb1'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_read(272): b'device::ro.product.name=sdk_gphone_x86_64_arm64;ro.product.model=sdk_gphone_x86_64_arm64;ro.product.device=generic_x86_64_arm64;features=sendrecv_v2_brotli,remount_shell,sendrecv_v2,abb_exec,fixed_push_mkdir,fixed_push_symlink_timestamp,abb,shell_v2,cmd,ls_v2,apex,stat_v2'
worker-low           | 2020-11-16 07:19:44 INFO     ADB device xxxx:5555 is connected: True
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xfe\x01\x00\x00\xb0\xaf\xba\xb1'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_write: b'root:\x00'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_read(24): b'OKAY\x86\x06\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_read(24): b'WRTE\x86\x06\x00\x00\x01\x00\x00\x00 \x00\x00\x00\x8c\x0b\x00\x00\xa8\xad\xab\xba'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_read(32): b'adbd is already running as root\n'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00\x86\x06\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_read(24): b'CLSE\x86\x06\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00\x86\x06\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
worker-low           | 2020-11-16 07:19:44 INFO     local_path: ./file_store/00_file_storage/libs/frida-server-14.0.8-android-arm
worker-low           | 2020-11-16 07:19:44 INFO     device_path: /data/local/tmp/frida-server-14.0.8-android-arm
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xf7\x01\x00\x00\xb0\xaf\xba\xb1'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_write: b'sync:\x00'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_read(24): b'CLSE\x86\x06\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_read(24): b'OKAY\x87\x06\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:65536 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:131072 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:196608 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:262144 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:327680 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:393216 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:458752 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:524288 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:589824 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:655360 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:720896 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:786432 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:851968 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:917504 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 INFO     ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:983040 total_bytes:8814864
worker-low           | 2020-11-16 07:19:44 DEBUG    bulk_write: b'WRTE\x01\x00\x00\x00\x87\x06\x00\x00\xb5\x00\x0f\x00\xdd\x15l\x05\xa8\xad\xab\xba'

[JeffLIrion]

In lines like this:

ADB Push-Progress: /data/local/tmp/frida-server-14.0.8-android-arm bytes_written:65536 total_bytes:8814864

Where does the bytes_written number come from?

I know there's an issue regarding using this package with an Android emulator (#81), so I'm actually a bit surprised it got as far as it did.

From simply looking at the log, all I can say is that the Python code is waiting for an OKAY message to arrive, but it never does. It tries to receive a new message, but it's empty, and so you get that unpack error about it expecting 24 bytes but receiving 0 bytes.

I'd need to write a unit test that uses your output in order to investigate further.

[7homasSutter]

The total bytes_written comes from the progress_callback function of the adb_device.push(...) method in adb_device.py (Line 516). I used it like this:

adb_device.push(local_path, device_path,
                           progress_callback=push_progress_callback,
                           transport_timeout_s=30,
                           read_timeout_s=30)

I just log everything that comes from the callback:

def push_progress_callback(device_path, bytes_written, total_bytes):
    logging.info(f"ADB Push-Progress: {device_path} bytes_written:{bytes_written} total_bytes:{total_bytes}")

To open the connection via the port 5555 using the standard adb keys works for me with this code example:

def load_adb_rsa_signer():
    adbkey_path = os.path.expanduser("~/.android/adbkey")
    with open(adbkey_path) as f:
        priv = f.read()
    with open(adbkey_path + '.pub') as f:
        pub = f.read()
    return PythonRSASigner(pub, priv)


def open_emulator_connection(emulator_url, emulator_port):
    rsa_signer = load_adb_rsa_signer()
    adb_device = connect_adb_device_tcp(emulator_url, emulator_port, rsa_signer)
    is_connected = is_device_available(adb_device)
    if not is_connected:
        ValueError(f"Could not connect ADB device {emulator_url}:{emulator_port}")
    logging.info(f"ADB device {emulator_url}:{emulator_port} is connected: {is_connected}")
    return adb_device

[JeffLIrion]

Can you try it with a really small file and see if it works. Something like echo 'hello world' > test.txt would be ideal.

[7homasSutter]

I just tested it with the test.txt and I've got the same error again. However, something is definitely strange because yesterday evening I was able to push one or two rather small (<= 2 MB) files to the emulator. The same files don't work anymore so I just tested to reconnect several times and send the test.txt and it worked sometimes. So it seems that it is sporadically working with small files and never with large ones.

It's probably hard for you to debug if you can't test it yourself. I would recommend that you take the time to set up an Android Emulator in a docker container. That takes around 15 minutes of your time. Here a small how to do it:

1. Just clone the repo from Docker Emu
2. cd to the cloned directory and execute ./configure.sh && emu-docker interactive --> Choose version 30 with x86_x64 stable to have the same emulator like I have.
3. ./create_web_container.sh -p user1,passwd1
4. docker-compose -f js/docker/docker-compose.yaml -f js/docker/development.yaml up

And then you should have a running Android emulator running with adb exposed at 5555 or 5554. You can see it on the web on https://localhost as well. I hope that will help you debugging.

[JeffLIrion]

I created a branch and a draft pull request for investigating this issue. Here's a comment that I left: #134 (comment)

[JeffLIrion]

I just tested it with the test.txt and I've got the same error again. However, something is definitely strange because yesterday evening I was able to push one or two rather small (<= 2 MB) files to the emulator. The same files don't work anymore so I just tested to reconnect several times and send the test.txt and it worked sometimes. So it seems that it is sporadically working with small files and never with large ones.

Can you please provide two logs for this "hello world" test file, one for a case where it succeeds and one for a case where it fails.

[7homasSutter]

Working ADB-Push log with hello world text file.:

flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'CNXN\x00\x00\x00\x01\x00\x00\x10\x00\x13\x00\x00\x00g\x05\x00\x00\xbc\xb1\xa7\xb1'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'host::6192d3cf48b5\x00'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(24): b'CNXN\x01\x00\x00\x01\x00\x00\x10\x00\x10\x01\x00\x00\xa1f\x00\x00\xbc\xb1\xa7\xb1'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(272): b'device::ro.product.name=sdk_gphone_x86_64_arm64;ro.product.model=sdk_gphone_x86_64_arm64;ro.product.device=generic_x86_64_arm64;features=sendrecv_v2_brotli,remount_shell,sendrecv_v2,abb_exec,fixed_push_mkdir,fixed_push_symlink_timestamp,abb,shell_v2,cmd,ls_v2,apex,stat_v2'
flask-web            | 2020-11-23 12:14:56 INFO     ADB device xxxxx:5555 is connected: True
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xfe\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'root:\x00'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(24): b'OKAYiT\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(24): b'WRTEiT\x00\x00\x01\x00\x00\x00 \x00\x00\x00\x8c\x0b\x00\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(32): b'adbd is already running as root\n'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00iT\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(24): b'CLSEiT\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00iT\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:14:56 INFO     local_path: ./file_store/00_file_storage/libs/test.txt
flask-web            | 2020-11-23 12:14:56 INFO     device_path: /data/local/tmp/test.txt
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xf7\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'sync:\x00'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(24): b'CLSEiT\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(24): b'OKAYjT\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:14:56 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:12 total_bytes:12
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'WRTE\x01\x00\x00\x00jT\x00\x00B\x00\x00\x00\xa8\x14\x00\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: bytearray(b'SEND\x1e\x00\x00\x00/data/local/tmp/test.txt,33272DATA\x0c\x00\x00\x00hello world\nDONE\xc0\xa7\xbb_')
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(24): b'OKAYjT\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(24): b'WRTEjT\x00\x00\x01\x00\x00\x00\x08\x00\x00\x004\x01\x00\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(8): b'OKAY\x00\x00\x00\x00'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00jT\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00jT\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:14:56 DEBUG    bulk_read(24): b'CLSEjT\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'

I couldn't trigger the problem with the test.txt anymore. After sending the 1000 test.txt times I decided to increase the file size until the problem starts to happen and it seems to start between 140KB to 145KB of data. With 142KB I would say 9 of ten times it works and the 10th time it fails. After increasing the size over 142KB it stats to fail nearly every time.

Log-File with 142KB that fails with timeout:

flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_write: b'CNXN\x00\x00\x00\x01\x00\x00\x10\x00\x13\x00\x00\x00g\x05\x00\x00\xbc\xb1\xa7\xb1'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_write: b'host::c5d603f9a727\x00'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_read(24): b'CNXN\x01\x00\x00\x01\x00\x00\x10\x00\x10\x01\x00\x00\xa1f\x00\x00\xbc\xb1\xa7\xb1'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_read(272): b'device::ro.product.name=sdk_gphone_x86_64_arm64;ro.product.model=sdk_gphone_x86_64_arm64;ro.product.device=generic_x86_64_arm64;features=sendrecv_v2_brotli,remount_shell,sendrecv_v2,abb_exec,fixed_push_mkdir,fixed_push_symlink_timestamp,abb,shell_v2,cmd,ls_v2,apex,stat_v2'
flask-web            | 2020-11-23 12:45:45 INFO     ADB device xxxx:5555 is connected: True
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xfe\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_write: b'root:\x00'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_read(24): b'OKAYfV\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_read(24): b'WRTEfV\x00\x00\x01\x00\x00\x00 \x00\x00\x00\x8c\x0b\x00\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_read(32): b'adbd is already running as root\n'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00fV\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_read(24): b'CLSEfV\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00fV\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:45:45 INFO     local_path: ./file_store/00_file_storage/libs/test.txt
flask-web            | 2020-11-23 12:45:45 INFO     device_path: /data/local/tmp/test.txt
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xf7\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_write: b'sync:\x00'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_read(24): b'CLSEfV\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_read(24): b'OKAYgV\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:45:45 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:65536 total_bytes:141852
flask-web            | 2020-11-23 12:45:45 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:131072 total_bytes:141852
flask-web            | 2020-11-23 12:45:45 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:141852 total_bytes:141852
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_write: b'WRTE\x01\x00\x00\x00gV\x00\x00b*\x02\x00\xcf\xfap\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-23 12:45:45 DEBUG    bulk_write: bytearray(b'SEND\x1e\x00\x00\x00/data/local/tmp/test.txt,33272DATA\x00\x00\x01\x00hello world\n6020813393115291018308864451756852473844549771230553274019875173525511163873500444811237248....
<LOTS OF DATA>
...
24365507532766797058257757822432716594523867292474757570615\n8116418268033688475580223253494948603537184329744599083311334953737050247127839879240255833527455107807664847505065047983484396\n\nDONE\xf9\xae\xbb_')

Log-File with 142KB that worked:

flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b'CNXN\x00\x00\x00\x01\x00\x00\x10\x00\x13\x00\x00\x00g\x05\x00\x00\xbc\xb1\xa7\xb1'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b'host::c5d603f9a727\x00'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(24): b'CNXN\x01\x00\x00\x01\x00\x00\x10\x00\x10\x01\x00\x00\xa1f\x00\x00\xbc\xb1\xa7\xb1'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(272): b'device::ro.product.name=sdk_gphone_x86_64_arm64;ro.product.model=sdk_gphone_x86_64_arm64;ro.product.device=generic_x86_64_arm64;features=sendrecv_v2_brotli,remount_shell,sendrecv_v2,abb_exec,fixed_push_mkdir,fixed_push_symlink_timestamp,abb,shell_v2,cmd,ls_v2,apex,stat_v2'
flask-web            | 2020-11-23 12:47:12 INFO     ADB device xxxxx:5555 is connected: True
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xfe\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b'root:\x00'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(24): b'OKAYkV\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(24): b'WRTEkV\x00\x00\x01\x00\x00\x00 \x00\x00\x00\x8c\x0b\x00\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(32): b'adbd is already running as root\n'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00kV\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(24): b'CLSEkV\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00kV\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:47:12 INFO     local_path: ./file_store/00_file_storage/libs/test.txt
flask-web            | 2020-11-23 12:47:12 INFO     device_path: /data/local/tmp/test.txt
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xf7\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b'sync:\x00'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(24): b'CLSEkV\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(24): b'OKAYlV\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:47:12 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:65536 total_bytes:141852
flask-web            | 2020-11-23 12:47:12 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:131072 total_bytes:141852
flask-web            | 2020-11-23 12:47:12 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:141852 total_bytes:141852
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b"WRTE\x01\x00\x00\x00lV\x00\x00b*\x02\x00'\xfap\x00\xa8\xad\xab\xba"
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: bytearray(b'SEND\x1e\x00\x00\x00/data/local/tmp/test.txt,33272DATA\x00\x00\x01\x00hello world\n6020813393115291018308864451756852473844549771230553274019875173525511163873500444811237248869802657723987122733883328526226736949680510879....
<LOTS OF DATA>
.....824365507532766797058257757822432716594523867292474757570615\n8116418268033688475580223253494948603537184329744599083311334953737050247127839879240255833527455107807664847505065047983484396\n\nDONEP\xaf\xbb_')
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(24): b'OKAYlV\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(24): b'WRTElV\x00\x00\x01\x00\x00\x00\x08\x00\x00\x004\x01\x00\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(8): b'OKAY\x00\x00\x00\x00'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00lV\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00lV\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-23 12:47:12 DEBUG    bulk_read(24): b'CLSElV\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'

[JeffLIrion]

Can you try this with my issue133 branch. You should be able to install it via:

pip install https://github.com/JeffLIrion/adb_shell/archive/issue133.zip

[7homasSutter]

I just tested it with your branch and I still got the problem. The hello world goes always through but larger files won't.

Working Log - File 142KB:

flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'CNXN\x00\x00\x00\x01\x00\x00\x10\x00\x13\x00\x00\x00\xf1\x05\x00\x00\xbc\xb1\xa7\xb1'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'host::f6afcec641a5\x00'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(24): bytearray(b'CNXN\x01\x00\x00\x01\x00\x00\x10\x00\x10\x01\x00\x00\xa1f\x00\x00\xbc\xb1\xa7\xb1')
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(272): b'device::ro.product.name=sdk_gphone_x86_64_arm64;ro.product.model=sdk_gphone_x86_64_arm64;ro.product.device=generic_x86_64_arm64;features=sendrecv_v2_brotli,remount_shell,sendrecv_v2,abb_exec,fixed_push_mkdir,fixed_push_symlink_timestamp,abb,shell_v2,cmd,ls_v2,apex,stat_v2'
flask-web            | 2020-11-26 11:27:39 INFO     ADB device xxx:5555 is connected: True
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xfe\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'root:\x00'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(24): bytearray(b'OKAY\xcd\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6')
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(24): bytearray(b'WRTE\xcd\x00\x00\x00\x01\x00\x00\x00 \x00\x00\x00\x8c\x0b\x00\x00\xa8\xad\xab\xba')
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(32): b'adbd is already running as root\n'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00\xcd\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(24): bytearray(b'CLSE\xcd\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba')
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00\xcd\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-26 11:27:39 INFO     local_path: ./file_store/00_file_storage/libs/test.txt
flask-web            | 2020-11-26 11:27:39 INFO     device_path: /data/local/tmp/test.txt
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xf7\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'sync:\x00'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(24): bytearray(b'CLSE\xcd\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba')
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(24): bytearray(b'OKAY\xce\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6')
flask-web            | 2020-11-26 11:27:39 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:65536 total_bytes:141852
flask-web            | 2020-11-26 11:27:39 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:131072 total_bytes:141852
flask-web            | 2020-11-26 11:27:39 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:141852 total_bytes:141852
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'WRTE\x01\x00\x00\x00\xce\x00\x00\x00b*\x02\x00\xe8\xf9p\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: bytearray(b'SEND\x1e\x00\x00\x00/data/local/tmp/test.txt,33272DATA\x00\x00\x01\x00hello world\n6020813393115291018308864451756852473844549771230553274019875173525511163873500444811237248088951714603052752360262642567865853\n62019670723085224280559694160199106632325301418271889756902275607286508298553649630132823700 <MORE DATA>
10144077054469603044\n1378563204070129032409938042343154208174485755861395799608824865872543930138962034925792279431758568493941395394754047686715676\n8867499345143102872671197738475892292486346568581939250404454964808538362896520373387072413955104371842316500056740851235207639\n2274346030168140429762079586632175197653839654847793978202115595048824365507532766797058257757822432716594523867292474757570615\n8116418268033688475580223253494948603537184329744599083311334953737050247127839879240255833527455107807664847505065047983484396\n\nDONE+\x91\xbf_')
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(24): bytearray(b'OKAY\xce\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6')
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(24): bytearray(b'WRTE\xce\x00\x00\x00\x01\x00\x00\x00\x08\x00\x00\x004\x01\x00\x00\xa8\xad\xab\xba')
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(8): b'OKAY\x00\x00\x00\x00'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00\xce\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00\xce\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-26 11:27:39 DEBUG    bulk_read(24): bytearray(b'CLSE\xce\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba')

Error Log - File 142KB:

flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_write: b'CNXN\x00\x00\x00\x01\x00\x00\x10\x00\x13\x00\x00\x00\xf1\x05\x00\x00\xbc\xb1\xa7\xb1'
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_write: b'host::f6afcec641a5\x00'
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_read(24): bytearray(b'CNXN\x01\x00\x00\x01\x00\x00\x10\x00\x10\x01\x00\x00\xa1f\x00\x00\xbc\xb1\xa7\xb1')
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_read(272): b'device::ro.product.name=sdk_gphone_x86_64_arm64;ro.product.model=sdk_gphone_x86_64_arm64;ro.product.device=generic_x86_64_arm64;features=sendrecv_v2_brotli,remount_shell,sendrecv_v2,abb_exec,fixed_push_mkdir,fixed_push_symlink_timestamp,abb,shell_v2,cmd,ls_v2,apex,stat_v2'
flask-web            | 2020-11-26 11:27:03 INFO     ADB device xxx:5555 is connected: True
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xfe\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_write: b'root:\x00'
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_read(24): bytearray(b'OKAY\xc9\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6')
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_read(24): bytearray(b'WRTE\xc9\x00\x00\x00\x01\x00\x00\x00 \x00\x00\x00\x8c\x0b\x00\x00\xa8\xad\xab\xba')
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_read(32): b'adbd is already running as root\n'
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00\xc9\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_read(24): bytearray(b'CLSE\xc9\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba')
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00\xc9\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-26 11:27:03 INFO     local_path: ./file_store/00_file_storage/libs/test.txt
flask-web            | 2020-11-26 11:27:03 INFO     device_path: /data/local/tmp/test.txt
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xf7\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_write: b'sync:\x00'
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_read(24): bytearray(b'CLSE\xc9\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba')
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_read(24): bytearray(b'OKAY\xca\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6')
flask-web            | 2020-11-26 11:27:03 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:65536 total_bytes:141852
flask-web            | 2020-11-26 11:27:03 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:131072 total_bytes:141852
flask-web            | 2020-11-26 11:27:03 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:141852 total_bytes:141852
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_write: b'WRTE\x01\x00\x00\x00\xca\x00\x00\x00b*\x02\x00\xc4\xf9p\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-26 11:27:03 DEBUG    bulk_write: bytearray(b'SEND\x1e\x00\x00\x00/data/local/tmp/test.txt,33272DATA\x00\x00\x01\x00hello world\n6020813393115291018308864451756852473844549771230553274019875173525511163873500444811237248088951714603052752360262642567865853\n620196707230852242805596941601991066323253014182718897569022756072865082985536496301328237008336162
<More Data>
2034925792279431758568493941395394754047686715676\n8867499345143102872671197738475892292486346568581939250404454964808538362896520373387072413955104371842316500056740851235207639\n2274346030168140429762079586632175197653839654847793978202115595048824365507532766797058257757822432716594523867292474757570615\n8116418268033688475580223253494948603537184329744599083311334953737050247127839879240255833527455107807664847505065047983484396\n\nDONE\x07\x91\xbf_')

Error:
<Some more Stactrace>
flask-web            |     push_file(adb_device, local_path, device_path)
flask-web            |   File "/var/www/scripts/dynamic_analysis/emulator_control/adb/adb_wrapper.py", line 61, in push_file
flask-web            |     return adb_device.push(local_path, device_path,
flask-web            |   File "/usr/local/lib/python3.8/site-packages/adb_shell/adb_device.py", line 557, in push
flask-web            |     self._push(stream, _device_path, st_mode, mtime, progress_callback, adb_info, filesync_info)
flask-web            |   File "/usr/local/lib/python3.8/site-packages/adb_shell/adb_device.py", line 609, in _push
flask-web            |     for cmd_id, _, data in self._filesync_read_until([], [constants.OKAY, constants.FAIL], adb_info, filesync_info):
flask-web            |   File "/usr/local/lib/python3.8/site-packages/adb_shell/adb_device.py", line 1093, in _filesync_read_until
flask-web            |     cmd_id, header, data = self._filesync_read(expected_ids + finish_ids, adb_info, filesync_info)
flask-web            |   File "/usr/local/lib/python3.8/site-packages/adb_shell/adb_device.py", line 1014, in _filesync_read
flask-web            |     self._filesync_flush(adb_info, filesync_info)
flask-web            |   File "/usr/local/lib/python3.8/site-packages/adb_shell/adb_device.py", line 979, in _filesync_flush
flask-web            |     self._write(filesync_info.send_buffer[:filesync_info.send_idx], adb_info)
flask-web            |   File "/usr/local/lib/python3.8/site-packages/adb_shell/adb_device.py", line 961, in _write
flask-web            |     self._read_until([constants.OKAY], adb_info)
flask-web            |   File "/usr/local/lib/python3.8/site-packages/adb_shell/adb_device.py", line 835, in _read_until
flask-web            |     cmd, remote_id2, local_id2, data = self._read(expected_cmds, adb_info)
flask-web            |   File "/usr/local/lib/python3.8/site-packages/adb_shell/adb_device.py", line 764, in _read
flask-web            |     msg += self._transport.bulk_read(msg_length, adb_info.transport_timeout_s)
flask-web            |   File "/usr/local/lib/python3.8/site-packages/adb_shell/transport/tcp_transport.py", line 127, in bulk_read
flask-web            |     raise TcpTimeoutException(msg)
flask-web            | adb_shell.exceptions.TcpTimeoutException: Reading from xxx:5555 timed out (30 seconds)

[JeffLIrion]

It looks like it basically traded one error for another. Previously, it failed because it tried to unpack a message that was 0 bytes when it expected a message that was 24 bytes. With this branch, it timed out trying to read 24 bytes.

[JeffLIrion]

Before doing adb_device.push(...), print out adb_device._maxdata and try setting adb_device._maxdata = 2048.

[7homasSutter]

Good Morning @JeffLIrion ,
I just tested setting the adb_device._maxdata to 2048 (on your branch) and that seems to solve the problem. I was able to upload several files with more than 20MB in size.

flask-web            | 2020-11-30 07:09:16 INFO     ADB device xxxx:5555 is connected: True
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xfe\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_write: b'root:\x00'
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_read(24): bytearray(b'OKAYZ\x07\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6')
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_read(24): bytearray(b'WRTEZ\x07\x00\x00\x01\x00\x00\x00 \x00\x00\x00\x8c\x0b\x00\x00\xa8\xad\xab\xba')
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_read(32): b'adbd is already running as root\n'
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_write: b'OKAY\x01\x00\x00\x00Z\x07\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6'
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_read(24): bytearray(b'CLSEZ\x07\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba')
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_write: b'CLSE\x01\x00\x00\x00Z\x07\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba'
flask-web            | 2020-11-30 07:09:16 INFO     local_path: ./file_store/00_file_storage/libs/test.txt
flask-web            | 2020-11-30 07:09:16 INFO     device_path: /data/local/tmp/test.txt
flask-web            | 2020-11-30 07:09:16 INFO     adb_device._maxdata: 1048576
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_write: b'OPEN\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\xf7\x01\x00\x00\xb0\xaf\xba\xb1'
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_write: b'sync:\x00'
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_read(24): bytearray(b'CLSEZ\x07\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xbc\xb3\xac\xba')
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_read(24): bytearray(b'OKAY[\x07\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6')
flask-web            | 2020-11-30 07:09:16 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:1024 total_bytes:503168
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_write: b'WRTE\x01\x00\x00\x00[\x07\x00\x00.\x04\x00\x00\xaa\xdd\x00\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_write: bytearray(b'SEND\x1e\x00\x00\x00/data/local/tmp/test.txt,33272DATA\x00\x04\x00\x009254835974458887629672873635789957411886024698554157393849494864228024962939550688297074527198420261051675205999609689838587412\n7948702662533481896767559573369920938242346354580061545409242090168773727371802699309443935396635866263937828773324526334321892\n7929250312741837331511829643632683169694074912332726993582394725302<some more logs>...
348547865459237835407372374738389274773789264\n3524314516560200536698529022539598732463389124803873184044464663165630452635665559603483233341839268186056673186867104904449866\n3388466377320953222057779182433549144340237502432464295061371141084500222833875925546082542869030852833895137466510262849050187\n2359980877010447170873386178573828860442255448874794721230413368694441497441338856684036949118353204002591974711928301953002372\n')
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_read(24): bytearray(b'OKAY[\x07\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xb0\xb4\xbe\xa6')
flask-web            | 2020-11-30 07:09:16 INFO     ADB Push-Progress: /data/local/tmp/test.txt bytes_written:2048 total_bytes:503168
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_write: b'WRTE\x01\x00\x00\x00[\x07\x00\x00\x08\x04\x00\x009\xd2\x00\x00\xa8\xad\xab\xba'
flask-web            | 2020-11-30 07:09:16 DEBUG    bulk_write: bytearray(b'DATA\x00\x04\x00\x00637261355715280100302383643440699786309673934
<ENDLESS MORE LOGS>

[JeffLIrion]

@atti92 given that you submitted this pull request: #105

Do you have any insight into why the emulator is causing adb_device._maxdata to be 1048576? Thomas said that when setting adb_device._maxdata = 2048 he was able to push files successfully.

[atti92]

I am digging into it, but based on the response to the CNXN, the emulator should in theory support that payload.
by the way, the ADB code has been moved on the google side here (need to change comments): https://android.googlesource.com/platform/system/adb/+/refs/heads/master

[atti92]

based on this:
https://android.googlesource.com/platform/system/adb/+/refs/heads/master/transport.cpp#785
and this:
https://android.googlesource.com/platform/system/adb/+/refs/heads/master/adb.h#35

maxdata should be at maximum 256k

found a comment, which could be related.
The device might send an error message, which we ignore by sending data continuosly without reading?
https://android.googlesource.com/platform/system/adb/+/master/file_sync_service.cpp#279