ESP32 "slow serial" causes installation failures? (AttributeError: 'NoneType' object has no attribute 'ls' during make nyansat SERIAL=..))

[conorpwr]

I know this isn't directly an antenny issue but given I had an issue with the ESP32 hardware suggested on the part list on the website, I thought I'd create an issue here for anyone else who ran into the same issue.

I was having repeated issues with trying to install the software on the ESP32 where it would throw an error for being unable to ls the ESP32 and throwing an exception:

make nyansat SERIAL=/dev/cu.usbserial-0001 
git submodule update --init
cd lib/BNO055; git checkout 4422248bc82a79b4aec9cc90599f28de60e37c76
HEAD is now at 4422248 .cal_status returns bytearray to avoid allocation.
cd lib/PCA9685; git checkout 0fea2736f99a2840f0d644be866f6abd5bc14b48
HEAD is now at 0fea273 Updating readme for archiving
cd lib/micropython; git checkout c2317a3a8d5f184de2f816078d91be699274b94
M       tools/pyboard.py
HEAD is now at c2317a3a8 nrf/Makefile: Disable ROM text compression when compiling for debug.
cd lib/micropygps; git checkout 95b739381c8feb7c6b91b46db42646074c52a609
HEAD is now at 95b7393 Merge pull request #29 from donnyw/feature/gsv_util_function
cd lib/simple-pid; git checkout 7edd3d4c860cb02876ec455591f11193db18a94b
HEAD is now at 7edd3d4 Update changelog
python3 -m nyansat.station.installer /dev/cu.usbserial-0001
INFO:antenny_installer:Connecting to the device at /dev/cu.usbserial-0001
b'\x1b[0;32mI (539) cpu_start: Pro cpu up.\x1b[0m\r\n\x1b[0;32mI (539) cpu_start: Application information:\x1b[0m\r\n\x1b[0;32mI (539) cpu_start: Compile time:     Aug 20 2020 00:54:56\x1b[0m\r\n\x1b[0;32mI (542) cpu_start: ELF file SHA256:  0000000000000000...\x1b[0m\r\n\x1b[0;32mI (548) cpu_start: ESP-IDF:          v3.3.2\x1b[0m\r\n\x1b[0;32mI (553) cpu_start: Starting app cpu, entry point is 0x40082f30\x1b[0m\r\n\x1b[0;32mI (0) cpu_start: App cpu up.\x1b[0m\r\n\x1b[0;32mI (563) heap_init: Initializing. RAM available for dynamic allocation:\x1b[0m\r\n\x1b[0;32mI (570) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (576) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (582) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (588) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (595) heap_init: At 3FFCA9E8 len 00015618 (85 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (601) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM\x1b[0m\r\n\x1b[0;32mI (607) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM\x1b[0m\r\n\x1b[0;32mI (613) heap_init: At 4009DE28 len 000021D8 (8 KiB): IRAM\x1b[0m\r\n\x1b[0;32mI (620) cpu_start: Pro cpu start user code\x1b[0m\r\n\x1b[0;32mI (303) cpu_start: Starting scheduler on PRO CPU.\x1b[0m\r\n\x1b[0;32mI (0) cpu_start: Starting scheduler on APP CPU.\x1b[0m\r\nMicroPython v1.12-665-g60f5b941e on 2020-08-20; ESP32 module with ESP32\r\nType "help()" for more information.\r\n>>> '
WARNING:antenny_installer:Retrying to connect to the ESP32 device, attempt 0/3
b'ro cpu up.\x1b[0m\r\n\x1b[0;32mI (539) cpu_start: Application information:\x1b[0m\r\n\x1b[0;32mI (539) cpu_start: Compile time:     Aug 20 2020 00:54:56\x1b[0m\r\n\x1b[0;32mI (542) cpu_start: ELF file SHA256:  0000000000000000...\x1b[0m\r\n\x1b[0;32mI (548) cpu_start: ESP-IDF:          v3.3.2\x1b[0m\r\n\x1b[0;32mI (553) cpu_start: Starting app cpu, entry point is 0x40082f30\x1b[0m\r\n\x1b[0;32mI (0) cpu_start: App cpu up.\x1b[0m\r\n\x1b[0;32mI (563) heap_init: Initializing. RAM available for dynamic allocation:\x1b[0m\r\n\x1b[0;32mI (570) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (576) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (582) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (588) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (595) heap_init: At 3FFCA9E8 len 00015618 (85 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (601) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM\x1b[0m\r\n\x1b[0;32mI (607) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM\x1b[0m\r\n\x1b[0;32mI (613) heap_init: At 4009DE28 len 000021D8 (8 KiB): IRAM\x1b[0m\r\n\x1b[0;32mI (620) cpu_start: Pro cpu start user code\x1b[0m\r\n\x1b[0;32mI (303) cpu_start: Starting scheduler on PRO CPU.\x1b[0m\r\n\x1b[0;32mI (0) cpu_start: Starting scheduler on APP CPU.\x1b[0m\r\nMicroPython v1.12-665-g60f5b941e on 2020-08-20; ESP32 module with ESP32\r\nType "help()" for more information.\r\n>>> '
WARNING:antenny_installer:Retrying to connect to the ESP32 device, attempt 1/3
b'\x1b[0;32mI (539) cpu_start: Pro cpu up.\x1b[0m\r\n\x1b[0;32mI (539) cpu_start: Application information:\x1b[0m\r\n\x1b[0;32mI (539) cpu_start: Compile time:     Aug 20 2020 00:54:56\x1b[0m\r\n\x1b[0;32mI (542) cpu_start: ELF file SHA256:  0000000000000000...\x1b[0m\r\n\x1b[0;32mI (548) cpu_start: ESP-IDF:          v3.3.2\x1b[0m\r\n\x1b[0;32mI (553) cpu_start: Starting app cpu, entry point is 0x40082f30\x1b[0m\r\n\x1b[0;32mI (0) cpu_start: App cpu up.\x1b[0m\r\n\x1b[0;32mI (563) heap_init: Initializing. RAM available for dynamic allocation:\x1b[0m\r\n\x1b[0;32mI (570) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (576) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (582) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (588) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (594) heap_init: At 3FFCA9E8 len 00015618 (85 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (601) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM\x1b[0m\r\n\x1b[0;32mI (607) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM\x1b[0m\r\n\x1b[0;32mI (613) heap_init: At 4009DE28 len 000021D8 (8 KiB): IRAM\x1b[0m\r\n\x1b[0;32mI (620) cpu_start: Pro cpu start user code\x1b[0m\r\n\x1b[0;32mI (303) cpu_start: Starting scheduler on PRO CPU.\x1b[0m\r\n\x1b[0;32mI (0) cpu_start: Starting scheduler on APP CPU.\x1b[0m\r\nMicroPython v1.12-665-g60f5b941e on 2020-08-20; ESP32 module with ESP32\r\nType "help()" for more information.\r\n>>> '
WARNING:antenny_installer:Retrying to connect to the ESP32 device, attempt 2/3
INFO:antenny_installer:Connected, welcome to the Antenny installer!
Are you sure you want to erase all files on the device at /dev/cu.usbserial-0001? (y/N) y
Traceback (most recent call last):
  File "/usr/local/Cellar/python/3.7.7/Frameworks/Python.framework/Versions/3.7/lib/python3.7/runpy.py", line 193, in _run_module_as_main
    "__main__", mod_spec)
  File "/usr/local/Cellar/python/3.7.7/Frameworks/Python.framework/Versions/3.7/lib/python3.7/runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "/Users/conor/code/esptool2/antenny/nyansat/station/installer/__main__.py", line 324, in <module>
    installer.install(only_core_reinstall=args.core_install)
  File "/Users/conor/code/esptool2/antenny/nyansat/station/installer/__main__.py", line 276, in install
    self._clean_files(ignore_lib=only_core_reinstall)
  File "/Users/conor/code/esptool2/antenny/nyansat/station/installer/__main__.py", line 78, in _clean_files
    files = self._file_explorer.ls()
AttributeError: 'NoneType' object has no attribute 'ls'
make: *** [nyansat] Error 1

Based on what was discussed in scientifichackers/ampy#19 I edited the enter_raw_repl function with pyboard.py for mpfshell to add in a time.sleep(2) immediately after the first self.con.write(b"\r\x03\x03") and then another time.sleep(2) after the first while section as per that GitHub issue. So it now looks something like this:

    def enter_raw_repl(self):

        time.sleep(0.5)   # allow some time for board to reset
        self.con.write(b"\r\x03\x03")  # ctrl-C twice: interrupt any running program
        time.sleep(2)

        # flush input (without relying on serial.flushInput())
        n = self.con.inWaiting()
        while n > 0:
            self.con.read(n)
            n = self.con.inWaiting()
        time.sleep(2)

Once that change was made the install appeared to work perfectly. Based on some dubious adds of print() statements to various sections, my theory is that for whatever reason this ESP32 seems to respond slower then expected and the output didn't match what was expected (the code was looking for a > when it was still showing intro messages) and threw an error. The baud rate was left at 115200 as well. Hope this helps anyone who might be running into a similar issue.

[ruffruffruffie]

Hi conorpwr! Thanks for noting this issue and providing a potential solution; we really appreciate it! Just to confirm, is this problem localized to mpfshell? If so, I suggest we open an issue in their repository and address this issue at the root. Additionally, we can add safeguards in our installation script for the timebeing!