Code is reloaded when there is no write

[Roming22]

CircuitPython version

Adafruit CircuitPython 8.0.0 on 2023-02-06; SparkFun Pro Micro RP2040 with rp2040
Board ID:sparkfun_pro_micro_rp2040

Code/REPL

> sudo fatrace -c
md5sum(141934): RO /run/media/user/KEYBOARD-L/code.py
md5sum(141934): C /run/media/user/KEYBOARD-L/code.py

Behavior

Code stopped by auto-reload. Reloading soon.

Auto-reload is on. Simply save files over USB to run them or enter REPL to disable.

Description

No response

Additional information

I'm running on the Fedora 37 version.

Doing find | LC_ALL=C sort | cpio -o | md5sum on the CP drive before and after the reload shows the same checksum, showing that no files were modified.

There is a 0.5KB change in the iostat output, showing that maybe the OS tried to update metadata file (e.g. last accessed data). If that's true, since the filesystem does not support that attribute, nothing has actually been written to disk even though a write action was performed.

[dhalbert]

Could you explain the scenario? Did you do any writes slightly before this auto-reload? Or was the board quiescent for a long time?

Auto-reload is triggered when a write command comes down from USB. The code waits 0.75 seconds after the last write received before triggering an auto-reload, to allow multiple writes in quick succession.

So something is arriving from the host that is a write. The way to check this would be to use wireshark or similar to see what is actually arriving.

The FAT filesystem does support a last modified time. Could you elaborate on your comment since the filesystem does not support that attribute ? Thanks.

What editor are you using? Some editors don't flush to disk immediately. Or are you using cp from the command line or similar? If the latter, it's helpful to follow the cp with an immediate sync. Linux can delay writing for 10 seconds or more sometimes.

[Roming22]

I'm sorry, I meant "last accessed time", not "last modified". I've modified my original comment. I would expect the OS to try to update that metadata after each open on the file.

Minimally reproducible scenario:

• Unplug, re-plug the board.
• Open Mu and connect to serial console.
• The drive label has been changed to something else than "CIRCUITPY", so Mu is not able to interfere with the drive.
• Wait for a while: nothing happens.
• cat /path/to/drive/code.py.
• After a few seconds, the board auto-reloads.

[dhalbert]

I tried to reproduce this on Ubuntu 22.04. My code.py is just the print("Hello, world!") you get on a fresh filesystem.

I did not rename the drive. I connect to the board either with Mu or with tio /dev/ttyACM0. I see "Auto-reload is on..." Nothing happens. I cat /media/halbert/CIRCUITPY/code.py. Nothing happens after that.

So something is happening on your particular system that is causing a write. Do you have any indexing programs or other scanning utilities running? Do you see this on other than Fedora? What is in your code.py? If you make it very simple, does the same thing happen?

[RetiredWizard]

I tried to get this to happen from Debian 11 on my Sparkfun RP2040 Thingplus but rather than Mu, I used tio as the terminal. I'm not auto mounting the CIRCUITPY drive so I manually mounted after plugging in the board.

I couldn't get the reload to occur by just performing the cat /media/user/code.py but the board did reload when I perform the mount or unmount. I also noticed that the reload only occurred if I had a python script running. If I was at the REPL prompt mount/umount did not cause a reload.

[RetiredWizard]

Okay, I just use cat on a larger file and while I was typing in that last message the board did an auto-reload. It was much more than a few seconds though, probably closer to a minute after I typed out the file..

[RetiredWizard]

If I use the command cat /media/user/filename.py; sync the reload happens immediately, but only the first time I cat the file and only if a script is running.

[Roming22]

My understanding is that you've reproduced the problem. If that's not correct, let me know and I'll try to provide an easy way to reproduce the issue.

[dhalbert]

@Roming22 How large is your code.py, and was it running when you cat'd it?

[dhalbert]

You can disable auto-reload, if it is interfering with your work:

import supervisor
...
supervisor.runtime.autoreload = False

[Roming22]

The code is already running when the auto-reload happens.

I can reproduce the issue with very little code. Here's an example, where I hit ctrl-c as soon I see the reload happening.

> ls -lR /run/media/user/KEYBOARD-R/
/run/media/user/KEYBOARD-R/:
total 4
-rw-r--r--. 1 user user 158 Dec 31  2019 boot_out.txt
-rw-r--r--. 1 user user   0 Feb 12 12:29 boot.py
-rw-r--r--. 1 user user  76 Feb 14 21:17 code.py

> md5sum /run/media/user/KEYBOARD-R/* ; time sleep infinity;
4a0087c900ac9ba765eb7ff94962a656  /run/media/user/KEYBOARD-R/boot_out.txt
d41d8cd98f00b204e9800998ecf8427e  /run/media/user/KEYBOARD-R/boot.py
1c04612b608e48ffa15192099a4d11ae  /run/media/user/KEYBOARD-R/code.py
^C
real	0m37.184s
user	0m0.000s
sys	0m0.002s

> md5sum /run/media/user/KEYBOARD-R/* 
4a0087c900ac9ba765eb7ff94962a656  /run/media/user/KEYBOARD-R/boot_out.txt
d41d8cd98f00b204e9800998ecf8427e  /run/media/user/KEYBOARD-R/boot.py
1c04612b608e48ffa15192099a4d11ae  /run/media/user/KEYBOARD-R/code.py

As you can see the drive has nothing but my code, and a read on the files triggers a reload after ~40s. Nothing else is happening, as you can see that the md5 of the files did not change.

Thanks for the tip on how to deactivate, but the auto-reload is useful to my current development process, and I've mostly worked around the issue by caching the md5 of the files I copy.

[tannewt]

The md5sum won't consider file metadata. There may be writes to the FAT filesystem itself rather than the files in it. You could add a print within circuitpython if you are really curious about what block is being written to trigger the reload.

[Roming22]

@tannewt Correct. Here's another test that hopefully shows that the metadata has not been modified as well.

> stat /run/media/rarnaud/KEYBOARD-R/* >before.txt; cat /run/media/rarnaud/KEYBOARD-R/code.py; time sleep infinity;
from time import sleep

print()
while True:
    print(end=".")
    sleep(2)
^C
real	0m37.156s
user	0m0.000s
sys	0m0.002s



17:31:39 - MBA-FEDORA:~
> stat /run/media/rarnaud/KEYBOARD-R/* >after.txt; diff before.txt after.txt 

How would I activate the logging you're talking about? Assuming I get some kind of address on the disk, what can I do with that information to move the troubleshooting forward?

[dhalbert]

The metadata can be something invisible to you via the filesystem, such as the dirty bit. Or it may be that the host is doing a write that does not actually change a block.

The way to do the print is to be able to build CircuitPython yourself, and then insert an mp_printf(&mp_plat_print, ...) at the right place in the code. An alternative to this is to use wireshark and look at the USB traffic, which does not require a rebuild. wireshark I think will be able to parse the SCSI-like commands sent to the mSC device.