adafruit / circuitpython

CircuitPython - a Python implementation for teaching coding with microcontrollers
https://circuitpython.org
Other
4.02k stars 1.19k forks source link

Starting code upload crashes the board hard if the currently running code.py has an open & unflushed file on SD card. #9138

Open raquo opened 5 months ago

raquo commented 5 months ago

CircuitPython version

Code/REPL

# this is code.py

import digitalio
import board
import busio
import sdcardio
import storage
import os
import time

ledPin: digitalio.DigitalInOut = digitalio.DigitalInOut(board.D13)
ledPin.direction = digitalio.Direction.OUTPUT

ledPin.value = False

time.sleep(1)

spi = board.SPI()

# # Same effect:
# spi = busio.SPI(
#     clock = board.SCK,
#     MOSI = board.MOSI,
#     MISO = board.MISO
# )

cs = board.D10

sdcard = sdcardio.SDCard(spi, cs)
vfs = storage.VfsFat(sdcard)

storage.mount(vfs, "/sd")

existingFilenames = os.listdir("/sd")

print(existingFilenames)

newFilenames = [
    "FILE1.TXT",
    # "FILE2.TXT"
]

for filename in newFilenames:
    if filename in existingFilenames:
        print("removing {}".format(filename))
        os.remove("/sd/" + filename)
    print("creating {}".format(filename))
    file = open("/sd/" + filename, "w")
    # file.flush()

print("Done!")

ledPin.value = True

Behavior

When you upload this code for the first time and run it, the output is:

Auto-reload is on. Simply save files over USB to run them or enter REPL to disable.
code.py output:
['.Spotlight-V100']
creating FILE1.TXT
Done!

Code done running.

This is as expected. The problem happens when you try to upload a small change (e.g. change "Done!" to "Done!!" in the code) – at this point there is no further output, the board crashes very hard.

Description

Prerequisites:

Steps to reproduce:

The board and the CIRCUITPY drive will now completely freeze:

Disconnecting the board and connecting it again blinks the LEDs initially (even the D13 LED lights up for a fraction of a second), but after that the board goes dark and remains unresponsive. The CIRCUITPY drive never appears in MacOS Finder.app, and attempting to open Serial log in Mu causes the same freezing cycle as described above.

Disconnecting the board from the SD card (e.g. by removing the card from the reader, or disconnecting the SCK wire), and then re-connecting the board to the USB does revive the board and the CIRCUITPY drive. You can re-insert the SD card and Ctrl+D reload the code to get back to the initial conditions. However, the new code was not uploaded. Attempting to upload the code again will result in the same freezing cycle.

Additional information

Uncommenting file.flush() in the code resolves the issue.

So, it appears that having un-flushed open file while starting a file upload somehow kills the board. Also, I'm not sure if this is expected or not, but the open() call does not seem to create the file immediately, the file is only created on the SD CARD if file.flush() is uncommented.

See also my comment below, that likely gets closer to the root of the problem.

wiring photo

raquo commented 5 months ago

I just found a way to fix the problem without flush()-ing:

I needed to use the VFS object's open method: vfs.open("FILE1.TXT") instead of the global open("/sd/FILE1.TXT"). Then it seems to work fine, no crash.

This doc page says:

You can only have either your computer edit the CIRCUITPY drive files, or CircuitPython. You cannot have both write to the drive at the same time. (Bad Things Will Happen so we do not allow you to do it!)

And indeed, I am not allowed to create a file in the root directory: as expected, open("FILE.TXT", "w") throws OSError: [Errno 30] Read-only filesystem error.

In contrast, it seems that attempting to create a file on the SD card using the "global" open method might be bypassing this safety check, and causing the above-mentioned "Bad Things".

I think open("/sd/FILE1.TXT", "w") should either throw a similar OSError, or delegate to vfs.open if possible – either way will be better than a hard crash.

jepler commented 5 months ago

This looks like a real bug that we should fix.

My gut tells me that it has something to do with attempting to "finalize" all objects when the VM shuts down, which works on objects in an unpredictable order, so for instance it could be the case that the mounted filesystem object has been finalized and then the file object is finalized, leading to an error because it's no longer valid to make calls related to the filesystem object...

The vfs.open workaround is interesting, I wonder why it makes a difference.

However, in the meantime, you may find that your code is more robust if it uses a with statement to handle the lifetime of the file:

with open("/sd/" + filename, "w") as file:
   ... # operate on file, knowing it will be flushed and closed when the block exits
raquo commented 5 months ago

@jepler Sorry, I think I was wrong about vfs.open working.

It seemed to have fixed the issue, but I'm trying it again now, and it's freezing the same as the global open. I probably didn't set up the test correctly yesterday.

--

Thanks for the with suggestion. Just to add a bit of context: the file I'm writing is a log file. I'm keeping it perpetually open, and I write() ~30 bytes to it several times per second, and then flush() the file every few seconds. I figured that was the most efficient way to do it, to reduce the time spent writing data.

I guess I should instead accumulate the bytes-to-write in some variable, and run the entire with-open-write thing once every few seconds, as you said.