Corrupted FS when writing to SD Card

[jerryneedell]

executing this code has repeatedly resulted in a corrupted FS with teh current master CP 3.0 It often fails to allocate enough memory, but sometime runs. If it does all seem ok for awhile -then the FS seem to just disappear.... I have reproduced this on a feather_m0_express and on a feather_m0_supersized. Both with a featherwing Adalogger attached.

# Initialize and mount SD card of Featherboard adalogger
import board
import busio
import digitalio
import adafruit_pcf8523
import adafruit_sdcard
import storage
import adafruit_dht

# create the SPI bus and a digital output for the microSD card's c\s line
spi = busio.SPI(board.SCK, MOSI=board.MOSI, MISO=board.MISO)
cs = digitalio.DigitalInOut(board.D5)

# create the microSD card object and the filesystem object
sdcard = adafruit_sdcard.SDCard(spi, cs)
vfs = storage.VfsFat(sdcard)

# mount the microSD card's filesystem into the CircuitPython filesystem
storage.mount(vfs, "/sd")

# Now ready to read and write data from the sd card
with open("/sd/test.txt", "w") as f:
    f.write("Hello world!\r\n")

# open a file and read a line from it with similar code
with open("/sd/test.txt", "r") as f:
    print("Read line from file:")
    print(f.readline())

[jerryneedell]

The FS appears to remain OK until the next soft reboot of the system after execution of the code. Whe it reboots, the CIRCUITPY drive no longer appears on my Ubuntu linux system- It reamied connected to the REPL but if I then try import os os.listdir() it hangs and I have to physically reboot but the system is no longer responsive and I have to upload the eraser .uf2 to recover.

[jerryneedell]

interestingly - another program that writes to the SDCard runs with no ill effect

import time
import board
import busio
import adafruit_am2320
import adafruit_sdcard
import digitalio
import storage

# can also use board.SDA and board.SCL for neater looking code!
i2c = busio.I2C(board.SCL, board.SDA)
am2320 = adafruit_am2320.AM2320(i2c)

# Connect to the card and mount the filesystem.
spi = busio.SPI(board.SCK, board.MOSI, board.MISO)
cs = digitalio.DigitalInOut(board.D5)
sdcard = adafruit_sdcard.SDCard(spi, cs)
sdc = storage.VfsFat(sdcard)
storage.mount(sdc, "/sd_card")

while True:
    try:
       with open("/sd_card/log.txt", "a") as sdc:
            temperature = am2320.temperature
            humidity = am2320.relative_humidity
            print("Temperature:", temperature)
            print("Humidity:", humidity)
            sdc.write("{},{}\n".format(temperature,humidity))
            sdc.flush()
            time.sleep(3)
    except OSError:
        print("OSError reported")
        # These sensors are a bit flakey, its ok if the readings fail
        pass
    except RuntimeError:
        print("RunTime reported")
        pass
    time.sleep(2)

This runs and the FS is fine.

It's not clear if the issue is related to the RTC driver or to being very low on RAM... testing

[jerryneedell]

I can run this with no problem

jerryneedell@Ubuntu-Macmini:~/projects/feather_m0_express$ cat sdtest.py 
import adafruit_sdcard
import busio
import digitalio
import board
import storage

# Connect to the card and mount the filesystem.
spi = busio.SPI(board.SCK, board.MOSI, board.MISO)
cs = digitalio.DigitalInOut(board.D5)
sdcard = adafruit_sdcard.SDCard(spi, cs)
vfs = storage.VfsFat(sdcard)
storage.mount(vfs, "/sd")

# Use the filesystem as normal.
with open("/sd/test.txt", "w") as f:
    f.write("Hello world\n")
# open a file and read a line from it with similar code
with open("/sd/test.txt", "r") as f:
    print("Read line from file:")
    print(f.readline())

[jerryneedell]

causing the FS corruption by executing the code listed in the firs message is very reproducible on a feather_m0_express. Execute it - soft reboot (control-D ) FS goes away.

this time I can remount CIRCUITPY after a hard reset, but I can't get to REPL..

after "awhile (10s of seconds) CIRCUITPY unmounts and dmesg reports

[589874.611986] FAT-fs (sdc1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[589920.659885] usb 3-3.2: reset full-speed USB device number 112 using xhci_hcd
[589925.983849] usb 3-3.2: device descriptor read/64, error -110

I'm confused....

[jerryneedell]

I remove the import dht from the test code and it still causes the same problems. Sometimes it cannot allocate enough memory an fails. Sometimes is runs to completion - and corrupts the FS. Could the problem be due to being very low on available RAM when accessing h SD-Card.Still it is not the SD Card that gets corrupted, it is the CiRCUITPY FS.

[jerryneedell]

one more test case -- running this seems to execute OK and I can do a soft reboot, BUT at the next hard reset/power cycle, the FS is corrupted - I cant even get to REPL

import adafruit_sdcard
import busio
import digitalio
import board
import storage

# Connect to the card and mount the filesystem.
spi = busio.SPI(board.SCK, board.MOSI, board.MISO)
cs = digitalio.DigitalInOut(board.D5)
sdcard = adafruit_sdcard.SDCard(spi, cs)
vfs = storage.VfsFat(sdcard)
storage.mount(vfs, "/sd")

# Use the filesystem as normal.
with open("/sd/test.txt", "w") as f:
    f.write("Hello world\n")
# open a file and read a line from it with similar code
with open("/sd/test.txt", "r") as f:
    print("Read line from file:")
    print(f.readline())

[deshipu]

Wait a minute, filesystem corruption shouldn't affect REPL...

[jerryneedell]

Yikes -- something very odd is going on -- much of the above may be just red-herrings... I just tried erasing the FS on the feather_m0_express-- load the erase .uf2 then reload CP -- looks good - I get to REPL. Power cycle and the FS is corrupted again..

[deshipu]

I don't know if that's related, but I recently had some problems flashing the uf2 of the master — it would work the first time, but then flashing the same or similar image (with different frozen code) would result in a crash — not even USB or REPL visible — until I flash some completely different image (for example 2.x) and re-flash the master.

[dhalbert]

What versions of the UF2 bootloader are you both running? See INFO_UF2.TXT in the BOOT drive. You might try updating to the latest with an update-bootloader*.uf2 from https://github.com/adafruit/uf2-samd21/releases

[deshipu]

In my case that was on the µGame, so it's my own build of some really old version of the bootloader. Was there some change in 3.x that made it incompatible with the old bootloaders? That is why I didn't report it, by the way — I assumed it's something specific to µGame...

[jerryneedell]

UF2 Bootloader v1.21.0 SFHR
Model: Feather M0
Board-ID: SAMD21G18A-Feather-v0

I'll try updating

[dhalbert]

@deshipu I'm just trying to eliminate some possibilities. Also, the clock code for the SAMD21 was redone about 10 days ago with https://github.com/adafruit/circuitpython/pull/785. If either of you can reproduce the problem consistently, we can bisect to see if that (or something else) is causing a problem.

[jerryneedell]

updating bootloader did not help - in fact I then loaded current master and I could not even get to REPL or mount the FS.. I reverted to the released alpha6 and it is working fine.

[jerryneedell]

I then reloaded current master and REPL was OK but after power cycle -it is gone again

[jerryneedell]

should I try removing #785?

[dhalbert]

@jerryneedell sure

[jerryneedell]

hmmm -- cant revert it -- not sure what the conflicts are:

jerryneedell@Ubuntu-Macmini:~/projects/adafruit_github/circuitpython_master$ git checkout -b revert_785
Switched to a new branch 'revert_785'
jerryneedell@Ubuntu-Macmini:~/projects/adafruit_github/circuitpython_master$ git revert -m 1 d3a5d40
error: could not revert d3a5d40... Merge pull request #785 from notro/rtc_calibration
hint: after resolving the conflicts, mark the corrected paths
hint: with 'git add <paths>' or 'git rm <paths>'
hint: and commit the result with 'git commit'

[jerryneedell]

after trying th above revert - git diff shows:

jerryneedell@Ubuntu-Macmini:~/projects/adafruit_github/circuitpython_master$ git diff
diff --cc ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h
index bfa8c64,56e9c8b..0000000
--- a/ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h
+++ b/ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h
@@@ -46,15 -46,3 +46,18 @@@
                                 GD25Q16C

  #include "external_flash/external_flash.h"
++<<<<<<< HEAD
 +
 +#define BOARD_HAS_CRYSTAL 1
 +
 +#define DEFAULT_I2C_BUS_SCL (&pin_PA23)
 +#define DEFAULT_I2C_BUS_SDA (&pin_PA22)
 +
 +#define DEFAULT_SPI_BUS_SCK (&pin_PB11)
 +#define DEFAULT_SPI_BUS_MOSI (&pin_PB10)
 +#define DEFAULT_SPI_BUS_MISO (&pin_PA12)
 +
 +#define DEFAULT_UART_BUS_RX (&pin_PA11)
 +#define DEFAULT_UART_BUS_TX (&pin_PA10)
++=======
++>>>>>>> parent of d3a5d40... Merge pull request #785 from notro/rtc_calibration
diff --cc ports/atmel-samd/boards/metro_m0_express/mpconfigboard.h
index f798c5d,a433e99..0000000
--- a/ports/atmel-samd/boards/metro_m0_express/mpconfigboard.h
+++ b/ports/atmel-samd/boards/metro_m0_express/mpconfigboard.h
@@@ -47,15 -47,3 +47,18 @@@
                                 GD25Q16C

  #include "external_flash/external_flash.h"
++<<<<<<< HEAD
 +
 +#define BOARD_HAS_CRYSTAL 1
 +
 +#define DEFAULT_I2C_BUS_SCL (&pin_PA23)
 +#define DEFAULT_I2C_BUS_SDA (&pin_PA22)
 +
 +#define DEFAULT_SPI_BUS_SCK (&pin_PB11)
 +#define DEFAULT_SPI_BUS_MOSI (&pin_PB10)
 +#define DEFAULT_SPI_BUS_MISO (&pin_PA12)
 +
 +#define DEFAULT_UART_BUS_RX (&pin_PA11)
 +#define DEFAULT_UART_BUS_TX (&pin_PA10)
++=======
++>>>>>>> parent of d3a5d40... Merge pull request #785 from notro/rtc_calibration

[jerryneedell]

reverted to commit 64bd95ea0155834c2c4313c4137af198890a59bc which was the one previous to merging #785 -- seems to be working OK

[jerryneedell]

And with thsi commit -- the previous issues with writing to the SDCARD are resolved!!!

The case that corrupted the system repeatedly now works.

There have been a lot of commits since #785 that are not in place now, but this is a big improvement!!

[notro]

PR #785 introduces 3 clock changes:

1. It enables OSC32K: https://github.com/adafruit/circuitpython/pull/785/commits/f21c2494cb612b9f9316ab97096e55ab30a404b4

2. It reworks the samd21 clock setup: https://github.com/adafruit/circuitpython/commit/4adba515695eb4eddf994c6847a5b92cffed6c07 AFAICT this didn't change clock register values. This snippet reverts that change:

   
   diff --git a/ports/atmel-samd/supervisor/port.c b/ports/atmel-samd/supervisor/port.c
   index 8e6f2b185..103f39c75 100644
   --- a/ports/atmel-samd/supervisor/port.c
   +++ b/ports/atmel-samd/supervisor/port.c
   @@ -177,14 +177,8 @@ safe_mode_t port_init(void) {
    }
   #endif

-#ifdef SAMD21

• hri_nvmctrl_set_CTRLB_RWS_bf(NVMCTRL, 2);
• _pm_init();
• clock_init(); -#endif -#ifdef SAMD51 init_mcu(); -#endif

• board_init();

  // Configure millisecond timer initialization.

3. It enables the crystal as the source for clock generator 2: https://github.com/adafruit/circuitpython/commit/2893e795fcbe0b36313a409d7d994880a3602689 This snippet disables that:

   
   diff --git a/ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h b/ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h
   index bfa8c642a..ee8a9c62b 100644
   --- a/ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h
   +++ b/ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h
   @@ -47,8 +47,6 @@
   
   #include "external_flash/external_flash.h"

-#define BOARD_HAS_CRYSTAL 1

define DEFAULT_I2C_BUS_SCL (&pin_PA23)

define DEFAULT_I2C_BUS_SDA (&pin_PA22)

If you revert number 2 it also disables 3.

I'll see if I can replicate your problem later today.

[jerryneedell]

I tried the changes above on the current master:

jerryneedell@Ubuntu-Macmini:~/projects/adafruit_github/circuitpython_master/ports/atmel-samd$ git diff
diff --git a/ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h b/ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h
index bfa8c64..cfe1919 100644
--- a/ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h
+++ b/ports/atmel-samd/boards/feather_m0_express/mpconfigboard.h
@@ -47,7 +47,6 @@

 #include "external_flash/external_flash.h"

-#define BOARD_HAS_CRYSTAL 1

 #define DEFAULT_I2C_BUS_SCL (&pin_PA23)
 #define DEFAULT_I2C_BUS_SDA (&pin_PA22)
diff --git a/ports/atmel-samd/supervisor/port.c b/ports/atmel-samd/supervisor/port.c
index 8e6f2b1..a91165e 100644
--- a/ports/atmel-samd/supervisor/port.c
+++ b/ports/atmel-samd/supervisor/port.c
@@ -177,14 +177,7 @@ safe_mode_t port_init(void) {
     }
 #endif

-#ifdef SAMD21
-    hri_nvmctrl_set_CTRLB_RWS_bf(NVMCTRL, 2);
-    _pm_init();
-    clock_init();
-#endif
-#ifdef SAMD51
     init_mcu();
-#endif
     board_init();

     // Configure millisecond timer initialization.

but it still fails to reboot after power cycle.

reverting back to commit 64bd95ea0155834c2c4313c4137af198890a59bc restores it to working.

[notro]

I couldn't find a sd card breakout board to hook up to my feather M0 express, so I tried a M0 Adalogger I had, but I only get: OSError: no SD card So I'm unable to try and reproduce this :-/

[jerryneedell]

It does not need an SDCARD -- just compile load and start the REPL -- then power cycle and it will fail to boot to the REPL and eventually disconnect the USB port. Its not really related to the SD Card.

[notro]

Oh, I've done all my testing with 'feather_m0_express' and circuitplayground_express and I've never encountered any problems. I have run run tests for 2 days reading the time every second over raw repl to check for accuracy and never had a hiccup. I rarely power cycle, but I have done it occasionally to be sure that the clock changes didn't have any ill effects from cold boot.

[jerryneedell]

I am trying to do a "bisect" to find the commit that caused the problem and I think it is well beyond yours. Are you using the current master now?

[jerryneedell]

my attemp at a bisect gas identified this:

2c067edf540fcc1f1f4aa68f0992ce8480a954bb is the first bad commit
commit 2c067edf540fcc1f1f4aa68f0992ce8480a954bb
Author: Matt Land <mland@sparefoot.com>
Date:   Wed May 16 15:54:01 2018 -0400

    used pins.c instead of README.rst

:040000 040000 05f72a171e17efa3a33447fa3b571af3a2decdb5 2a454fbb36bb964794fd4c5830b2d630851b0f2f M  ports

[jerryneedell]

not convinced - tried previous commit to this and it still fails....

[jerryneedell]

narrowing it down -- this commit seem to work 99e34e38eb6a81e0722b31b085c2f24ea1111981

[notro]

Are you using the current master now?

Yes.

Are you having problems on a Feather M0 Express without any code.py, from cold boot to the REPL? Or do you get problems after some python code has run first?

[jerryneedell]

and this commit is OK 07c0a3227da24ef92e44a2457f94af71cc7f081c

@notro yes - the problem is on a clean flash - no code.py - I get no prompt from REPL and the host OS eventually drops the USB connection to it.

[jerryneedell]

but this one fails -- 6a8db03ade64bd2fdf5c7b5df54ad113a062e005 I was just walking up the merged PRs --this was #838

When I power cycle no REPL and eventually dmesg shows this after it disconnects

[ 2538.649880] usb 3-3.2: reset full-speed USB device number 43 using xhci_hcd
[ 2543.973797] usb 3-3.2: device descriptor read/64, error -110
[ 2559.590136] usb 3-3.2: device descriptor read/64, error -110
[ 2559.798119] usb 3-3.2: reset full-speed USB device number 43 using xhci_hcd
[ 2564.966245] usb 3-3.2: device descriptor read/64, error -110
[ 2580.582607] usb 3-3.2: device descriptor read/64, error -110
[ 2580.790594] usb 3-3.2: reset full-speed USB device number 43 using xhci_hcd
[ 2585.858648] xhci_hcd 0000:00:14.0: Timeout while waiting for setup device command
[ 2591.234822] xhci_hcd 0000:00:14.0: Timeout while waiting for setup device command
[ 2591.442796] usb 3-3.2: device not accepting address 43, error -62
[ 2591.542830] usb 3-3.2: reset full-speed USB device number 43 using xhci_hcd
jerryneedell@Ubuntu-Macmini:~$ 

[jerryneedell]

reverted to commit 07c0a3227da24ef92e44a2457f94af71cc7f081c and it seems to be OK - REPL works -- power cycle -- still get REPL and CIRCUITPY I can still run the sdcard test with out any problem as well

SO it looks like PR #838 is introducing a problem on power cycle.

[notro]

I'm working on Windows 10 and I just did a test connecting the board to a Raspberry Pi and it still worked. Do you have another computer than the Mac/Ubuntu to test with?

[jerryneedell]

I "tried" removing PR#838 from the current master, but the revert did not work so Idon't trust my resut - with failed but reverting to 07c0a3227da24ef92e44a2457f94af71cc7f081c works consistently.

@notro since my system works on some commits and not others I don't think it is the problem. Are you using the current master now - or your last commit. I think you last commit is just fine.

[notro]

I'm using current master:

$ git log --oneline -1
1eb412b44 (HEAD -> test, tag: patchbase, origin/master, origin/HEAD, master) Merge pull request #845 from matt-land/feature-default-serial

[jerryneedell]

just tried build of master - same version as you -- it inatillay boots to REPL after load, then after power cycle it failed on the Ubuntu system, my MACOS system and my raspberry PI. I'm puzzled!...

[jerryneedell]

as on the trinket, I can connect and the Nepoixel goes from green to white, but no REPL prompt..

[notro]

Can you upload a failing feather_m0_express firmware somewhere so I can try it? This is the one I'm currently trying: http://tronnes.org/downloads/feather_m0_express-firmware.uf2

[notro]

Or rather it's so small that you can zip it and e-mail it: noralf@tronnes.org

[jerryneedell]

I just tried yours and it seems to work!!! very odd -- send mine in a minute

[jerryneedell]

here is my failing version feather_m0_express.zip

[notro]

First soft reboot after upload gives repl, power cycling gives: Failed to recognize usb device. Same as you.

But now I have the same problem with a new build I just did! What is going on here? Reverting to the one I sent you, is working.

[jerryneedell]

@notro -- I guess I'm relieved - a bit....

[jerryneedell]

can you reproduce the one you sent me, was it built today or ealrier?

[notro]

The one I sent you was built 1 hour ago. I'm doing a fresh build now. This is mysterious, I'm starting to doubt my own sanity :-)

[jerryneedell]

I've been doubting mine all day! I made a new clone of the repo this morning and have been working with that. I still can get back to a working version consistently by reverting back before PR#838

[notro]

This is the strangest thing.

Looks like I've found a reproduceable way of flipping back and forth between working and not working. I have a build script that creates a git tag when checking out the code so I can easily dump out the commits I've done using git format-patch patchbase..HEAD.

So with that tag I get a firmware that can handle power cycling:

git tagging:

pi@agl:~/circuitpython/workdirs/test/circuitpython$ git tag patchbase
pi@agl:~/circuitpython/workdirs/test/circuitpython$ git log --oneline -1
1eb412b44 (HEAD -> test, tag: patchbase, origin/master, origin/HEAD, master) Merge pull request #845 from matt-land/feature-default-serial

(re)Build:

pi@agl:~/circuitpython$ rake compile
cd /home/pi/circuitpython/workdirs/test/circuitpython/ports/atmel-samd
make BOARD=feather_m0_express CROSS_COMPILE=/home/pi/opt/gcc-arm-none-eabi-7-2017-q4-major/bin/arm-none-eabi-
Use make V=1, make V=2 or set BUILD_VERBOSE similarly in your environment to increase build verbosity.
Generating build-feather_m0_express/genhdr/mpversion.h
QSTR not updated
../../shared-bindings/usb_hid/__init__.h:33:23: warning: size of 'common_hal_usb_hid_devices' differ from the size of original declaration [-Wlto-type-mismatch]
 extern mp_obj_tuple_t common_hal_usb_hid_devices;
                       ^
common-hal/usb_hid/__init__.c:127:16: note: 'common_hal_usb_hid_devices' was previously declared here
 mp_obj_tuple_t common_hal_usb_hid_devices = {
                ^

33932 bytes free in flash out of 253696 bytes ( 247.75 kb ).
3936 bytes free in ram for stack out of 32768 bytes ( 32.0 kb ).

Create build-feather_m0_express/firmware.bin
Create build-feather_m0_express/firmware.uf2
../../tools/uf2/utils/uf2conv.py -b 0x2000 -c -o build-feather_m0_express/firmware.uf2 build-feather_m0_express/firmware.bin
Converting to uf2, output size: 439808, start address: 0x2000
Wrote 439808 bytes to build-feather_m0_express/firmware.uf2.
cd -

Board REPL, the tag show up:

Adafruit CircuitPython patchbase-dirty on 2018-05-18; Adafruit Feather M0 Express with samd21g18
>>>

Next I remove the tag and rebuild, and it can't handle power cycling:

pi@agl:~/circuitpython/workdirs/test/circuitpython$ git tag -d patchbase
Deleted tag 'patchbase' (was 1eb412b44)
pi@agl:~/circuitpython/workdirs/test/circuitpython$ git log --oneline -1
1eb412b44 (HEAD -> test, origin/master, origin/HEAD, master) Merge pull request #845 from matt-land/feature-default-serial

Build:

pi@agl:~/circuitpython$ rake compile
cd /home/pi/circuitpython/workdirs/test/circuitpython/ports/atmel-samd
make BOARD=feather_m0_express CROSS_COMPILE=/home/pi/opt/gcc-arm-none-eabi-7-2017-q4-major/bin/arm-none-eabi-
Use make V=1, make V=2 or set BUILD_VERBOSE similarly in your environment to increase build verbosity.
Generating build-feather_m0_express/genhdr/mpversion.h
QSTR not updated
../../shared-bindings/usb_hid/__init__.h:33:23: warning: size of 'common_hal_usb_hid_devices' differ from the size of original declaration [-Wlto-type-mismatch]
 extern mp_obj_tuple_t common_hal_usb_hid_devices;
                       ^
common-hal/usb_hid/__init__.c:127:16: note: 'common_hal_usb_hid_devices' was previously declared here
 mp_obj_tuple_t common_hal_usb_hid_devices = {
                ^

33884 bytes free in flash out of 253696 bytes ( 247.75 kb ).
3936 bytes free in ram for stack out of 32768 bytes ( 32.0 kb ).

Create build-feather_m0_express/firmware.bin
Create build-feather_m0_express/firmware.uf2
../../tools/uf2/utils/uf2conv.py -b 0x2000 -c -o build-feather_m0_express/firmware.uf2 build-feather_m0_express/firmware.bin
Converting to uf2, output size: 439808, start address: 0x2000
Wrote 439808 bytes to build-feather_m0_express/firmware.uf2.
cd -

REPL, no tag instead commit ref:

Adafruit CircuitPython 3.0.0-alpha.6-142-g1eb412b44-dirty on 2018-05-18; Adafruit Feather M0 Express with samd21g18
>>>

[dhalbert]

When the version string changes boot_out.txt is rewritten to include the new version string. The file is read first to see if the string is the same. If the version string doesn't change then it's not rewritten.

Also your tag made the string shorter, though that doesn't seem so likely an issue.