Problem with boot.py

All ESP32 boards running MicroPython.
Target audience: MicroPython users with an ESP32 board.
Post Reply
paulg
Posts: 29
Joined: Fri Oct 23, 2015 1:06 pm

Problem with boot.py

Post by paulg » Sat Dec 28, 2019 3:54 pm

I have two TinyPICO boards and I use rshell to communicate with them. I have found that if I remove or overwrite boot.py the board hangs after a few more rshell file commands. Here is a transcript of a typical session:


Pauls-Mac-mini:TinyPICO paul$ esptool.py --chip esp32 --port /dev/tty.SLAB_USBtoUART erase_flash
esptool.py v2.7
<snipped>...
Pauls-Mac-mini:TinyPICO paul$ esptool.py --chip esp32 --port /dev/tty.SLAB_USBtoUART --baud 460800 write_flash -z 0x1000 firmware/esp32-idf3-20191220-v1.12.bin
esptool.py v2.7
<snipped>...
Pauls-Mac-mini:TinyPICO paul$ rshell
Using buffer-size of 32
Connecting to /dev/tty.SLAB_USBtoUART (buffer-size 32)...
Trying to connect to REPL connected
Testing if ubinascii.unhexlify exists ... Y
Retrieving root directories ... /boot.py/
Setting time ... Dec 27, 2019 11:14:18
Evaluating board_name ... pyboard
Retrieving time epoch ... Jan 01, 2000
Welcome to rshell. Use Control-D (or the exit command) to exit rshell.
/Users/paul/Projects/TinyPICO> ls -al /pyboard
139 Jan 1 2000 boot.py
/Users/paul/Projects/TinyPICO> rm /pyboard/boot.py
/Users/paul/Projects/TinyPICO> ls -al /pyboard
/Users/paul/Projects/TinyPICO> cp test24.py /pyboard/boot.py
/Users/paul/Projects/TinyPICO> ls -al /pyboard
<*** the board has hung, enter Ctrl-C to quit rshell>^C
Pauls-Mac-mini:TinyPICO paul$ rshell
Using buffer-size of 32
Connecting to /dev/tty.SLAB_USBtoUART (buffer-size 32)...
Trying to connect to REPL .. connected
Testing if ubinascii.unhexlify exists ...
<*** rshell hangs here>


At first I thought it was because I was removing the only file in the filesystem. However, that is not the case. If I copy other files across all is ok until I touch boot.py. If I quit rshell and invoke it again, it hangs at the point where it is looking for unhexlify (see above). The only way out is to use esptool to erase the flash and then write a new firmware image to the board. All is then fine again. The problem occurs with both v1.11 and v1.12 non-spiram firmwares and on both of my TinyPICO boards.

Can anyone reproduce this behaviour? Is it an esp32 issue or does it also happen on a pyboard? Any help will be appreciated!

User avatar
dhylands
Posts: 3821
Joined: Mon Jan 06, 2014 6:08 pm
Location: Peachland, BC, Canada
Contact:

Re: Problem with boot.py

Post by dhylands » Mon Dec 30, 2019 4:36 pm

rshell winds up doing lots of soft-resets, basically one per command sent. Some commands, like ls may require several command.

Each one of those soft resets causes boot,py to be executed. I'd don't recall exactly what happens when there is no boot.py, so I'd try connecting with a regular terminal and see what's happening on the bootup when boot.py is missing.

paulg
Posts: 29
Joined: Fri Oct 23, 2015 1:06 pm

Re: Problem with boot.py

Post by paulg » Mon Jan 20, 2020 5:51 pm

I am returning to this after taking a break over the holiday season. Thanks to @dhylands for your comments and suggestion.

I have simplified the scenario to two files; boot.py as below and test24.py which is copied to main.py on the MicroPython board.

Code: Select all

# boot.py: does nothing

Code: Select all

# test24.py: Basic loop timing test
print('\nHello. This is test 24')
from machine import Pin
led2=Pin(26, Pin.OUT)
while True:
    led2.on()
    led2.off()
I wired an LED and series resistor onto the led2 pin so that I can visually see when the program is running.

If I enter rshell with the program halted, then I can start it at the repl using Ctrl-D and interrupt it with Ctrl-C.
However, if I exit rshell with the program running and then re-enter rshell, I cannot interrupt the program with Ctrl-C.

In my previous post I stated that rshell hangs at the point where it is testing if ubinascii.unhexlify exists. That is not so. I should have been more patient and not exited rshell after a couple of seconds. After a 10 second pause the output continues.

Code: Select all

Pauls-Mac-mini:TinyPICO paul$ rshell
Using buffer-size of 32
Connecting to /dev/tty.SLAB_USBtoUART (buffer-size 32)...
Trying to connect to REPL  connected
Testing if ubinascii.unhexlify exists ... b'ets Jun  8 2016 00:22:57\r\n\r\nrst:0xc (SW_CPU_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)\r\nconfigsip: 188777542, SPIWP:0xee\r\nclk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00\r\nmode:DIO, clock div:2\r\nload:0x3fff0018,len:4\r\nload:0x3fff001c,len:4844\r\nload:0x40078000,len:9656\r\nload:0x40080400,len:6216\r\nentry 0x400806f0\r\n\x1b[0;32mI (458) cpu_start: Pro cpu up.\x1b[0m\r\n\x1b[0;32mI (458) cpu_start: Application information:\x1b[0m\r\n\x1b[0;32mI (458) cpu_start: Compile time:     Dec 20 2019 07:50:41\x1b[0m\r\n\x1b[0;32mI (461) cpu_start: ELF file SHA256:  0000000000000000...\x1b[0m\r\n\x1b[0;32mI (467) cpu_start: ESP-IDF:          v3.3\x1b[0m\r\n\x1b[0;32mI (472) cpu_start: Starting app cpu, entry point is 0x40083600\x1b[0m\r\n\x1b[0;32mI (464) cpu_start: App cpu up.\x1b[0m\r\n\x1b[0;32mI (483) heap_init: Initializing. RAM available for dynamic allocation:\x1b[0m\r\n\x1b[0;32mI (490) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (496) heap_init: At 3FFBA488 len 00025B78 (150 KiB): DRAM\x1b[0m\r\n\x1b[0;32mI (502) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM\x1b[0m\r\n\x1b[0;32mI (508) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM\x1b[0m\r\n\x1b[0;32mI (515) heap_init: At 40092D6C len 0000D294 (52 KiB): IRAM\x1b[0m\r\n\x1b[0;32mI (521) cpu_start: Pro cpu start user code\x1b[0m\r\n\x1b[0;32mI (204) cpu_start: Chip Revision: 1\x1b[0m\r\n\x1b[0;33mW (204) cpu_start: Chip revision is higher than the one configured in menuconfig. Suggest to upgrade it.\x1b[0m\r\n\x1b[0;32mI (207) 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\n\r\nHello. This is test 24\r\n'
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.5/bin/rshell", line 10, in <module>
    sys.exit(main())
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/rshell/command_line.py", line 4, in main
    rshell.main.main()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/rshell/main.py", line 2934, in main
    real_main()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/rshell/main.py", line 2896, in real_main
    connect(args.port, baud=args.baud, wait=args.wait, user=args.user, password=args.password)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/rshell/main.py", line 1286, in connect
    connect_serial(port, baud=baud, wait=wait)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/rshell/main.py", line 1319, in connect_serial
    dev = DeviceSerial(port, baud, wait)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/rshell/main.py", line 1609, in __init__
    Device.__init__(self, pyb)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/rshell/main.py", line 1373, in __init__
    unhexlify_exists = self.remote_eval(test_unhexlify)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/rshell/main.py", line 1497, in remote_eval
    return eval(self.remote(func, *args, **kwargs))
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/rshell/main.py", line 1475, in remote
    self.pyb.enter_raw_repl()
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/rshell/pyboard.py", line 198, in enter_raw_repl
    raise PyboardError('could not enter raw repl 1')
rshell.pyboard.PyboardError: could not enter raw repl 1
Pauls-Mac-mini:TinyPICO paul$ rshell
It is curious that rshell can connect to the repl in the 4th line, but not in the next line. I think the difference is the soft reset. I studied pboard.py and noted there were four instances of the "could not enter raw repl" message so I added a number to each of them to distinguish them. I did several experiments on the function enter_raw_repl(). I added a time.sleep(0.001) at the beginning and everything worked ok. I printed a '$' at the beginning and all was ok.

So, the problem could be a timing race. Presumably, the Ctrl-C's are emitted (line 186 of pyboard.py) whilst the RTOS is still starting up and are lost. Delaying them solves the problem. I am not entirely convinced by this hypothesis because it seems so finely balanced between working and failing.

So, firstly can anyone re-create this scenario on an ESP32 board? Secondly, does anyone have an alternative explanation?
NB The board is running the Generic non-SPIRAM firmware esp32-idf3-20191220-v1.12.bin.

Post Reply