dhylands / rshell

Remote Shell for MicroPython
MIT License
955 stars 136 forks source link

Transfer error in remote on STM32 #228

Closed camielverdult closed 5 months ago

camielverdult commented 5 months ago

Hello, there is one specific file that has suddenly (and now continuously) has errors when copying the file to an STM32. The file has the following content (this is not my code, used in a shared project):

Code (server.py, part of a canopen variant module) ```py import struct import sys from .base import SdoBase from .block import SdoBlockException, SdoBlock from .constants import * from .exceptions import * class SdoServer(SdoBase): # Creates an SDO server. def __init__(self, rx_cobid, tx_cobid, node): super().__init__(rx_cobid, tx_cobid, node.object_dictionary) self._node = node self._buffer = None self._toggle = 0 self._index = None self._subindex = None self.last_received_error = 0x00000000 self.sdo_block = None def on_request(self, can_id, data, timestamp): try: if self.sdo_block and self.sdo_block.state != BLOCK_STATE_NONE: if self.process_block(data): # Abort returns False return (command,) = struct.unpack_from("B", data, 0) ccs = command & 0xE0 if ccs == REQUEST_UPLOAD: self.init_upload(data) elif ccs == REQUEST_SEGMENT_UPLOAD: self.segmented_upload(command) elif ccs == REQUEST_DOWNLOAD: self.init_download(data) elif ccs == REQUEST_SEGMENT_DOWNLOAD: self.segmented_download(command, data) elif ccs == REQUEST_BLOCK_UPLOAD: self.block_upload(data) elif ccs == REQUEST_BLOCK_DOWNLOAD: self.block_download(data) elif ccs == REQUEST_ABORTED: self.request_aborted(data) else: self.abort(0x05040001) except SdoAbortedError as exc: self.abort(exc.code) self.sdo_block = None except KeyError as exc: self.abort(0x06020000) self.sdo_block = None except Exception as exc: _, index, subindex = struct.unpack_from(SDO_STRUCT, data) print(f"\n\nucanopen->sdo->server.py({can_id:03X}, {data})@{timestamp}\n") print(f"entry={index}:{subindex})n") sys.print_exception(exc) print("\n") # Reply with general error self.abort(0x08000025) def process_block(self, request): print("process_block") command, _, _ = struct.unpack_from(SDO_STRUCT, request) if command == 0x80: self.sdo_block = None # Abort received, do not reply return False if BLOCK_STATE_UPLOAD < self.sdo_block.state < BLOCK_STATE_DOWNLOAD: print("BLOCK_STATE_UPLOAD") # in upload state if self.sdo_block.state == BLOCK_STATE_UP_INIT_RESP: print("BLOCK_STATE_UP_INIT_RESP") # init response was sent, client required to send new request if (command & REQUEST_BLOCK_UPLOAD) != REQUEST_BLOCK_UPLOAD: raise SdoBlockException(0x05040001) if (command & START_BLOCK_UPLOAD) != START_BLOCK_UPLOAD: raise SdoBlockException(0x05040001) # now start blasting data to client from server self.sdo_block.update_state(BLOCK_STATE_UP_DATA) for seqno in range(1, self.sdo_block.req_blocksize + 1): block, last = self.sdo_block.get_single_upload_block(seqno) self.send_response(block) if last: break elif self.sdo_block.state == BLOCK_STATE_UP_DATA: print("BLOCK_STATE_UP_DATA") command, ackseq, newblk = struct.unpack_from( SDO_BLOCKACK_STRUCT, request ) if (command & REQUEST_BLOCK_UPLOAD) != REQUEST_BLOCK_UPLOAD: print("Command %02X", command) raise SdoBlockException(0x05040001) elif (command & BLOCK_TRANSFER_RESPONSE) != BLOCK_TRANSFER_RESPONSE: print("Command %02X", command) raise SdoBlockException(0x05040001) elif ackseq != self.sdo_block.last_seqno: self.sdo_block.data_uploaded = self.sdo_block.data_succesfull_upload self.sdo_block.req_blocksize = newblk if self.sdo_block.size == self.sdo_block.data_uploaded: print("BLOCK_STATE_UP_DATA last data") self.sdo_block.update_state(BLOCK_STATE_UP_END) response = bytearray(8) command = RESPONSE_BLOCK_UPLOAD command |= END_BLOCK_TRANSFER n = self.sdo_block.last_bytes << 2 command |= n print( "Last no byte: %d, CRC: x%04X", self.sdo_block.last_bytes, self.sdo_block.crc_value, ) struct.pack_into( SDO_BLOCKEND_STRUCT, response, 0, command, self.sdo_block.crc_value, ) self.send_response(response) else: for seqno in range(1, self.sdo_block.req_blocksize + 1): block, last = self.sdo_block.get_single_upload_block(seqno) self.send_response(block) if last: break elif self.sdo_block.state == BLOCK_STATE_UP_END: self.sdo_block = None elif BLOCK_STATE_DOWNLOAD < self.sdo_block.state: print("BLOCK_STATE_DOWNLOAD") else: # in neither raise SdoBlockException(0x08000022) return True def init_upload(self, request): _, index, subindex = struct.unpack_from(SDO_STRUCT, request) self._index = index self._subindex = subindex res_command = RESPONSE_UPLOAD | SIZE_SPECIFIED response = bytearray(8) data = self._node.get_data(index, subindex, check_readable=True) size = len(data) if size <= 4: # print("Expedited upload for 0x%X:%d", index, subindex) res_command |= EXPEDITED res_command |= (4 - size) << 2 response[4 : 4 + size] = data else: # print("Initiating segmented upload for 0x%X:%d", index, subindex) struct.pack_into("> 2) & 0x3) else: size = 4 self.download(index, subindex, request[4 : 4 + size]) else: print(f"Initiating segmented download for 0x{index:02x}:{subindex}") if command & SIZE_SPECIFIED: (size,) = struct.unpack_from("> 1) & 0x7) if self._buffer: self._buffer.extend(request[1:last_byte]) else: raise SdoAbortedError(0x08000022) if command & NO_MORE_DATA: self._node.set_data( self._index, self._subindex, self._buffer, check_writable=True ) res_command = RESPONSE_SEGMENT_DOWNLOAD # Add toggle bit res_command |= self._toggle # Toggle bit for next message self._toggle ^= TOGGLE_BIT response = bytearray(8) response[0] = res_command self.send_response(response) def send_response(self, response): self.network.send_message(self.tx_cobid, response) def abort(self, abort_code=0x08000000): # Abort current transfer. if not self._index: self._index = 0 if not self._subindex: self._subindex = 0 data = struct.pack( "

The environment is on WSL using rshell 0.0.32. I have compiled all files with mpy-cross (using the same version as the stm32 port binary flashed to the stm32) when this file started throwing errors during copy.

This is the log for copying the file:

camiel@WS1420:/mnt/c/Users/c.verdult/Documents/Repos/firmware$ rshell -p /dev/ttyS4 --debug --buffer-size 5000 'cp mpy_code/lib/ucanopen/sdo/server.py /flash/lib/ucanopen/sdo/server.py'
Debug = True
Port = /dev/ttyS4
Baud = 115200
User = micro
Password = python
Wait = 0
List = 0
nocolor = 0
ascii = 0
Timing = 0
Quiet = 0
BUFFER_SIZE = 5000
Cmd = [cp mpy_code/lib/ucanopen/sdo/server.py /flash/lib/ucanopen/sdo/server.py]
Using buffer-size of 5000
Connecting to /dev/ttyS4 (buffer-size 5000)...
Trying to connect to REPL . connected
Retrieving sysname ... ----- About to send 205 bytes of code to the pyboard -----
def sysname():
    try:
        import os
        return repr(os.uname().sysname)
    except:
        return repr('unknown')
output = sysname()
if output is None:
    print("None")
else:
    print(output)

-----
-----Response-----
b"'pyboard'\r\n"
-----
pyboard
Testing if ubinascii.unhexlify exists ... ----- About to send 286 bytes of code to the pyboard -----
def test_unhexlify():
    try:
        import ubinascii
    except:
        import binascii as ubinascii
    try:
        _ = ubinascii.unhexlify
        return True
    except:
        return False
output = test_unhexlify()
if output is None:
    print("None")
else:
    print(output)

-----
-----Response-----
b'True\r\n'
-----
Y
Retrieving root directories ... ----- About to send 150 bytes of code to the pyboard -----
def listdir(dirname):
    import os
    return os.listdir(dirname)
output = listdir('/')
if output is None:
    print("None")
else:
    print(output)

-----
-----Response-----
b"['flash']\r\n"
-----
/flash/
Setting time ... ----- About to send 1250 bytes of code to the pyboard -----
def set_time(rtc_time):
    rtc = None
    try:
        import pyb
        rtc = pyb.RTC()
        rtc.datetime(rtc_time)
    except:
        try:
            import pycom
            rtc_time2 = (rtc_time[0], rtc_time[1], rtc_time[2], rtc_time[4], rtc_time[5], rtc_time[6])
            import machine
            rtc = machine.RTC()
            rtc.init(rtc_time2)
        except:
            try:
                import machine
                rtc = machine.RTC()
                try:
                    rtc.datetime(rtc_time)
                except:
                    rtc.init(rtc_time)
            except:
                try:
                    import os
                    if os.uname().sysname == 'rp2':
                        setup_0 = rtc_time[0] << 12 | rtc_time[1] << 8 | rtc_time[2]
                        setup_1 = (rtc_time[3] % 7) << 24 | rtc_time[4] << 16 | rtc_time[5] << 8 | rtc_time[6]
                        machine.mem32[0x4005c004] = setup_0
                        machine.mem32[0x4005c008] = setup_1
                        machine.mem32[0x4005c00c] |= 0x10
                except:
                    pass
output = set_time((2024, 6, 3, 1, 13, 19, 59, 0))
if output is None:
    print("None")
else:
    print(output)

-----
-----Response-----
b'None\r\n'
-----
Jun 03, 2024 13:19:59
Evaluating board_name ... ----- About to send 479 bytes of code to the pyboard -----
def board_name(default):
    try:
        import board
        try:
            name = board.name
        except AttributeError:
            name = default
    except ImportError:
        name = default
    except BaseException as err:
        print('Error encountered executing board.py')
        import sys
        sys.print_exception(err)
        name = default
    return repr(name)
output = board_name('pyboard')
if output is None:
    print("None")
else:
    print(output)

-----
-----Response-----
b"'pyboard'\r\n"
-----
pyboard
Retrieving time epoch ... ----- About to send 215 bytes of code to the pyboard -----
def get_time_epoch():
    import time
    try:
      return time.gmtime(0)
    except:
      return (2000, 1, 1, 0, 0, 0, 0, 0)
output = get_time_epoch()
if output is None:
    print("None")
else:
    print(output)

-----
-----Response-----
b'(2000, 1, 1, 0, 0, 0, 5, 1)\r\n'
-----
Jan 01, 2000
Executing "cp mpy_code/lib/ucanopen/sdo/server.py /flash/lib/ucanopen/sdo/server.py"
----- About to send 236 bytes of code to the pyboard -----
def get_mode(filename):
    import os
    try:
        return os.stat(filename)[0]
    except OSError:
        return 0
output = get_mode('/flash/lib/ucanopen/sdo/server.py')
if output is None:
    print("None")
else:
    print(output)

-----
-----Response-----
b'32768\r\n'
-----
Copying '/mnt/c/Users/c.verdult/Documents/Repos/firmware/mpy_code/lib/ucanopen/sdo/server.py' to '/flash/lib/ucanopen/sdo/server.py' ...
----- About to send 1779 bytes of code to the pyboard -----
def recv_file_from_host(src_file, dst_filename, filesize, dst_mode='wb'):
    import sys
    try:
        import ubinascii
    except:
        import binascii as ubinascii
    import os
    if False:
        try:
            import micropython
            micropython.kbd_intr(-1)
        except:
            pass
    try:
        with open(dst_filename, dst_mode) as dst_file:
            bytes_remaining = filesize
            if not False:
                bytes_remaining *= 2
            buf_size = 5000
            write_buf = bytearray(buf_size)
            read_buf = bytearray(buf_size)
            while bytes_remaining > 0:
                sys.stdout.write('\x06')
                read_size = min(bytes_remaining, buf_size)
                buf_remaining = read_size
                buf_index = 0
                while buf_remaining > 0:
                    if False:
                        bytes_read = sys.stdin.buffer.readinto(read_buf, read_size)
                    else:
                        bytes_read = sys.stdin.readinto(read_buf, read_size)
                    if bytes_read > 0:
                        write_buf[buf_index:bytes_read] = read_buf[0:bytes_read]
                        buf_index += bytes_read
                        buf_remaining -= bytes_read
                if False:
                    dst_file.write(write_buf[0:read_size])
                else:
                    dst_file.write(ubinascii.unhexlify(write_buf[0:read_size]))
                if hasattr(os, 'sync'):
                    os.sync()
                bytes_remaining -= read_size
        return True
    except:
        return False
output = recv_file_from_host(None, '/flash/lib/ucanopen/sdo/server.py', 11428)
if output is None:
    print("None")
else:
    print(output)

-----
timed out or error in transfer to remote: b'F'
camielverdult commented 5 months ago

The same thing seems to happen when using the --ascii flag

camielverdult commented 5 months ago

Ampy has a similar issue, I am starting to think it's the file:

camiel@WS1420:/mnt/c/Users/c.verdult/Documents/Repos/firmware$ ampy --port /dev/ttyS4 put build/lib/ucanopen/sdo/server.mpy /flash/lib/ucanopen/sdo/server.mpy Traceback (most recent call last): File "/home/camiel/.local/bin/ampy", line 8, in sys.exit(cli()) File "/home/camiel/.local/lib/python3.10/site-packages/click/core.py", line 1157, in call return self.main(args, kwargs) File "/home/camiel/.local/lib/python3.10/site-packages/click/core.py", line 1078, in main rv = self.invoke(ctx) File "/home/camiel/.local/lib/python3.10/site-packages/click/core.py", line 1688, in invoke return _process_result(sub_ctx.command.invoke(sub_ctx)) File "/home/camiel/.local/lib/python3.10/site-packages/click/core.py", line 1434, in invoke return ctx.invoke(self.callback, ctx.params) File "/home/camiel/.local/lib/python3.10/site-packages/click/core.py", line 783, in invoke return __callback(args, **kwargs) File "/home/camiel/.local/lib/python3.10/site-packages/ampy/cli.py", line 264, in put board_files.put(remote, infile.read()) File "/home/camiel/.local/lib/python3.10/site-packages/ampy/files.py", line 223, in put self.pyboard.exec("f.write({0})".format(chunk)) File "/home/camiel/.local/lib/python3.10/site-packages/ampy/pyboard.py", line 279, in exec_ raise PyboardError('exception', ret, ret_err) ampy.pyboard.PyboardError: ('exception', b'', b'Traceback (most recent call last):\r\n File "", line 1, in \r\nOSError: 28\r\n')

camielverdult commented 5 months ago

I think I found the suspect, if I copy all my files except the server.mpy file my flash is full:

>>> import os
>>> statvfs_data = os.statvfs('/flash')
>>> _, f_frsize, f_blocks, f_bfree = (
...         statvfs_data[0],
...                 statvfs_data[1],
...         statvfs_data[2],
...         statvfs_data[3],
...     )
>>> fs_total_size = f_blocks * f_frsize
>>> fs_total_size_kB = fs_total_size / 1024
>>> fs_free_size = f_bfree * f_frsize
>>> fs_free_size_kB = fs_free_size / 1024
>>> fs_free_size_kB
0.0
>>> fs_total_size_kB
143.0

This does not make much sense to me, since the total size on disk of the files I am trying to copy is 92.0KB. In reality the flash is full after 88KB of data.

Edit: It makes much more sense after checking the statvfs output with an empty /flash folder:

MicroPython v1.22.2 on 2024-04-16; WIFLX_gt48468c1 with STM32G474
Type "help()" for more information.
>>> import os
>>> statvfs_data = os.statvfs('/flash')
>>> _, f_frsize, f_blocks, f_bfree = (
...         statvfs_data[0],
...                 statvfs_data[1],
...         statvfs_data[2],
...         statvfs_data[3],
...     )
>>> fs_total_size = f_blocks * f_frsize
>>> fs_total_size_kB = fs_total_size / 1024
>>> fs_free_size = f_bfree * f_frsize
>>> fs_free_size_kB = fs_free_size / 1024
>>> fs_free_size_kB
55.5
>>> fs_total_size_kB
143.0

So there is 87.5KB left on the flash for mpy files