nodemcu-firmware: File writes slow and fail well before SPIFFS filesystem space is exhausted

Expected behavior

Periodically appending chunks of data to a file on the SPIFFS filesystem is possible until the free space is exhausted, or nearly exhausted.

Actual behavior

There are increasing problems with writing chunks to a file as the filesystem fills up. It does not seem to be a problem with file size: having multiple smaller files still leads to the same problem.

  • Write speed slows considerably as the filesystem is filled to > 75% capacity.
  • File writes eventually fail completely with ~8% of the space left on the filesystem (230k+ for 4MB module)
  • The last few successful writes take 6-77 seconds instead of the normal ~15-75 milliseconds.
  • The points, in terms of space remaining, at which file writes slow or fail are repeatable between runs.

This problem has been present since at least v2.2.0, a year or more. Once file writes fail, it is usually not possible to successfully download any file from SPIFFS using ESPlorer or nodemcu-uploader until large files are deleted.

In actual use cases, the same problem happens with an ESP8266 that turns on periodically, collects some data, and writes to csv. The problems seem to happen at roughly similar filesizes across different individual ESP8266 modules.

Abbreviated function output, with write time for 1024 byte chunks in milliseconds:

For 4MB module:
Used: 1506 | Remain: 3445728 | Time: 180.279
Used: 2510 | Remain: 3444724 | Time: 12.285
Used: 3514 | Remain: 3443720 | Time: 12.366
Used: 4518 | Remain: 3442716 | Time: 12.362
...
Used: 291411 | Remain: 3155823 | Time: 71.817
Used: 292415 | Remain: 3154819 | Time: 71.83
Used: 293419 | Remain: 3153815 | Time: 71.957
...
Used: 2741924 | Remain: 705310 | Time: 77.094
Used: 2742928 | Remain: 704306 | Time: 77.077
Used: 2743932 | Remain: 703302 | Time: 77.078
Used: 2744936 | Remain: 702298 | Time: 262.307
Used: 2745940 | Remain: 701294 | Time: 320.053
Used: 2747195 | Remain: 700039 | Time: 321.103
...
Used: 3210541 | Remain: 236693 | Time: 326.398
Used: 3211545 | Remain: 235689 | Time: 327.534
Used: 3212549 | Remain: 234685 | Time: 318.57
Used: 3213804 | Remain: 233430 | Time: 1690.133
Used: 3214808 | Remain: 232426 | Time: 8580.37
Used: 3215812 | Remain: 231422 | Time: 6809.032
Used: 3216816 | Remain: 230418 | Time: 6137.508
Used: 3217820 | Remain: 229414 | Time: 7142.574
Writing file failed. f:write() output: 	nil

~~~~~~~~~~~~~~~~~~~~~~~~~

For 1MB module: 
Used: 1506 | Remain: 457824 | Time: 43.308
Used: 2510 | Remain: 456820 | Time: 16.082
Used: 3514 | Remain: 455816 | Time: 16.178
...
Used: 353408 | Remain: 105922 | Time: 26.187
Used: 354412 | Remain: 104918 | Time: 26.173
Used: 355416 | Remain: 103914 | Time: 26.377
Used: 356420 | Remain: 102910 | Time: 301.693
Used: 357424 | Remain: 101906 | Time: 302.709
Used: 358428 | Remain: 100902 | Time: 301.955
...
Used: 419421 | Remain: 39909 | Time: 333.119
Used: 420425 | Remain: 38905 | Time: 333.52
Used: 421429 | Remain: 37901 | Time: 331.577
Used: 422433 | Remain: 36897 | Time: 3329.875
Used: 423437 | Remain: 35893 | Time: 76869.023
Used: 424441 | Remain: 34889 | Time: 77039.751
Writing file failed. f:write() output: 	nil


Test code

function test_filesystem(mult)

    chunk = string.rep("0123456789ABCDEF", 2 ^ mult)
    t = tmr.create()

    remain, _, _ = file.fsinfo()

    while remain > 500 do

        start = tmr.now()
    
        f = file.open( "test.txt", "a")
        
        if f then
        
            success = f:write(chunk)

            if success then
            
                f:close()
                time = (tmr.now() - start) / 1000
                remain, used, _ = file.fsinfo()                
                print("Used: " .. used .. " | Remain: " .. remain .. " | Time: " .. time)
                
            else
            
                f:close()
                print("Writing file failed. f:write() output: ", success)
                return
                
            end
            
        else
            print("Opening file failed")
            return
        end

    end

end

-- 0 = 16 bit chunks, 1 = 32, 4 = 256, 5 = 512, 6 = 1024, etc.
test_filesystem(6)

NodeMCU version

2.2.1 master, commit: 4905381c004bdeaf744a60bb940c1906c2e052d4

Hardware

WeMos D1 mini (4MB), and WeMos D1 mini Lite (1MB)

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Reactions: 1
  • Comments: 24 (4 by maintainers)

Most upvoted comments

The referenced SPIFFS material already answers some of the points that you are raising as issues, yet you don’t seem to be aware of this; this seems to me be be a valid reason for asking whether you had read this material. Why does doing this constitute rudeness on my part?

  • The SPIFFS documentation advises that the SPIFFS_info() is inaccurate because of metadata overhead, so why not just set your soft limit for capacity at 80% of the nominal FS size, say, and then you will have a good balance of performance and stability.
  • Don’t close the file after each write as this defeats the write-though caching system which both hits performance and causes bad logical page fragmentation, reducing the life of the flash memory chip.
  • If you want to measure bare write performance then don’t embed instrumentation within the write loop that materially impacts on this performance.

These issues are known to the SPIFFS authors. If you want to lobby to request architectural or functional changes on SPIFFS issues and we will pick them up in due course once they are incorporated into a new SPIFFS Release. We are not planning any such changes in the interim.


Lastly on a point of list governance: you are seeking help here gratis, I am here trying to provide this help, also gratis. I am not here to be accused of having an unbelievable attitude; having nothing good to say; being rude; being ham-fisted and juvenile – all your ad hominems directed at me. I don’t understand why you use language that is going to drop your change of getting help to zero. I provide my help and my contributions for free, so that developers like yourself can make free use of them. Whatever you feel about my conduct, I am trying to engage constructively, and I make my points and ask my questions for what I view as valid reasons.

This is the first time on GitHub that I have found it necessary to give the following advisory. Please engage constructively and refrain from ad hominem comments. Any further breaches will result in your account being blocked from submitting to this list and your content here will be deleted.

@marcelstoer @devsaurus @pjsg @jmattsson

I don’t think this should be simply closed. It’s still clearly a bug and NOT the way things are intended to work, as @TerryE is saying. There’s even a bug already posted on the spiffs repository.

At the very least, if some space is simply unusable, the nodemcu file.write() wrapper could prevent writes when a certain amount of space is remaining on spiffs. This would at least prevent the entire filesystem from becoming unstable.

More broadly, I’m disappointed in your approach to bug handling. I’ve spent some time building a bug report. I didn’t ask for it to be fixed, I simply submitted the bug. I might even be willing to work on fixes myself. Unilaterally putting that down, closing the bug report, and complaining that there is no free lunch is not community-oriented, and rather ham-fisted, just juvenile behavior. I would think this is not at all in the interest of collaboration, and I would hope that you all reconsider how you are interacting.

See SPIFFS FAQ

file.write() calls SPIFFS to do the work. It is essentially a wrapper. Your issue isn’t with what the file module does; it is with the underlying SPIFFS functionality.

This a community project. You are using the Lua firmware because of the 100s possibly by now 1000+ hours that I and others contribute for nothing. If you want to suggest a clarification to the documentation, then please read Contributing for how you can do that 5 minutes work yourself.

Your comments and attitude are unbelievably “helpful”, for what is a legitimate bug report. If you have nothing good to say, don’t say it. And if you don’t want bug reports, don’t solicit them.

There are all kinds of ways to mitigate this, some (e.g. documentation) would take 5 minutes.

See the link and the related repository. We import SPIFFS and are not the maintainers. There may be a GC issue giving a false high. What SPIFFS is all about is giving a usable basic FS on the < 5 cent flash device that is on most ESP modules. If you don’t want the additional cost / power draw then you need to work within the H/W limitations. There’s no free lunch. Sorry.

Sorry but what you describe is expected behaviour for SPIFFS. See SPIFFS Performance and Optimizing. SPIFFS is not a high performance FS; it is designed to balance safety, wear levelling and performance for bare flash devices. It does not maintained any form of linked structures so attempting to open a non-existent file will end up doing a full scan of the FS. When it needs a new logical page, it does a scan of the FS until it finds one free, and so these scan times rise considerably as the used % of the FS approaches 100%. Ditto fseek() times giving an O(N²) characteristic.

If you want good performance from SPIFFS:

  • Keep the % utilisation low
  • Keep the partition size low as well.

If you want to do a lot of local logging then the best thing to do is to use FatFS on an SDCard. Use a decent branded SD Card as these embed a proper wear-levelling controller on the device so FatFS give a balance of performance and life.