components/nvs: handle more cases where sudden power off may happen

This commit fixes several issues with state handling in nvs::Page. It also adds extra consistency checks in nvs::PageManger initialization.
These changes were verified with a new long-running test ("test recovery from sudden poweroff"). This test works by repeatedly performing same pseudorandom sequence of calls to nvs_ APIs. Each time it repeats the sequence, it introduces a failure into one of flash operations (write or erase). So if one iteration of this test needs, say, 25000 flash operations, then this test will run 25000 iterations, each time introducing the failure point at different location.

components/nvs_flash/include/nvs.h

@@ -36,6 +36,7 @@ typedef uint32_t nvs_handle;
 #define ESP_ERR_NVS_NOT_ENOUGH_SPACE    (ESP_ERR_NVS_BASE + 0x05)
 #define ESP_ERR_NVS_INVALID_NAME        (ESP_ERR_NVS_BASE + 0x06)
 #define ESP_ERR_NVS_INVALID_HANDLE      (ESP_ERR_NVS_BASE + 0x07)
+#define ESP_ERR_NVS_REMOVE_FAILED       (ESP_ERR_NVS_BASE + 0x08)
 #define ESP_ERR_NVS_KEY_TOO_LONG        (ESP_ERR_NVS_BASE + 0x09)
 #define ESP_ERR_NVS_PAGE_FULL           (ESP_ERR_NVS_BASE + 0x0a)
 #define ESP_ERR_NVS_INVALID_STATE       (ESP_ERR_NVS_BASE + 0x0b)
@@ -92,6 +93,10 @@ esp_err_t nvs_open(const char* name, nvs_open_mode open_mode, nvs_handle *out_ha
  *             - ESP_ERR_NVS_INVALID_NAME if key name doesn't satisfy constraints
  *             - ESP_ERR_NVS_NOT_ENOUGH_SPACE if there is not enough space in the
  *               underlying storage to save the value
+ *             - ESP_ERR_NVS_REMOVE_FAILED if the value wasn't updated because flash
+ *               write operation has failed. The value was written however, and
+ *               update will be finished after re-initialization of nvs, provided that
+ *               flash operation doesn't fail again.
  */
 esp_err_t nvs_set_i8  (nvs_handle handle, const char* key, int8_t value);
 esp_err_t nvs_set_u8  (nvs_handle handle, const char* key, uint8_t value);

components/nvs_flash/src/nvs_page.cpp

@@ -99,15 +99,12 @@ esp_err_t Page::writeEntry(const Item& item)
         return err;
     }
 
-    if (mNextFreeEntry == 0) {
-        mFirstUsedEntry = 0;
+    if (mFirstUsedEntry == INVALID_ENTRY) {
+        mFirstUsedEntry = mNextFreeEntry;
     }
 
     ++mUsedEntryCount;
-
-    if (++mNextFreeEntry == ENTRY_COUNT) {
-        alterPageState(PageState::FULL);
-    }
+    ++mNextFreeEntry;
 
     return ESP_OK;
 }
@@ -144,7 +141,7 @@ esp_err_t Page::writeItem(uint8_t nsIndex, ItemType datatype, const char* key, c
     // primitive types should fit into one entry
     assert(totalSize == ENTRY_SIZE || datatype == ItemType::BLOB || datatype == ItemType::SZ);
 
-    if (mNextFreeEntry + entriesCount > ENTRY_COUNT) {
+    if (mNextFreeEntry == INVALID_ENTRY || mNextFreeEntry + entriesCount > ENTRY_COUNT) {
         // page will not fit this amount of data
         return ESP_ERR_NVS_PAGE_FULL;
     }
@@ -296,10 +293,14 @@ esp_err_t Page::eraseEntryAndSpan(size_t index)
         } else {
             span = item.span;
             for (ptrdiff_t i = index + span - 1; i >= static_cast<ptrdiff_t>(index); --i) {
+                if (mEntryTable.get(i) == EntryState::WRITTEN) {
+                    --mUsedEntryCount;
+                }
                 rc = alterEntryState(i, EntryState::ERASED);
                 if (rc != ESP_OK) {
                     return rc;
                 }
+                ++mErasedEntryCount;
             }
         }
     }
@@ -313,9 +314,10 @@ esp_err_t Page::eraseEntryAndSpan(size_t index)
     if (index == mFirstUsedEntry) {
         updateFirstUsedEntry(index, span);
     }
-
-    mErasedEntryCount += span;
-    mUsedEntryCount -= span;
+    
+    if (index + span > mNextFreeEntry) {
+        mNextFreeEntry = index + span;
+    }
 
     return ESP_OK;
 }
@@ -324,7 +326,11 @@ void Page::updateFirstUsedEntry(size_t index, size_t span)
 {
     assert(index == mFirstUsedEntry);
     mFirstUsedEntry = INVALID_ENTRY;
-    for (size_t i = index + span; i < mNextFreeEntry; ++i) {
+    size_t end = mNextFreeEntry;
+    if (end > ENTRY_COUNT) {
+        end = ENTRY_COUNT;
+    }
+    for (size_t i = index + span; i < end; ++i) {
         if (mEntryTable.get(i) == EntryState::WRITTEN) {
             mFirstUsedEntry = i;
             break;
@@ -358,10 +364,6 @@ esp_err_t Page::moveItem(Page& other)
     if (err != ESP_OK) {
         return err;
     }
-    err = eraseEntry(mFirstUsedEntry);
-    if (err != ESP_OK) {
-        return err;
-    }
 
     size_t span = entry.span;
     size_t end = mFirstUsedEntry + span;
@@ -374,6 +376,8 @@ esp_err_t Page::moveItem(Page& other)
         if (err != ESP_OK) {
             return err;
         }
+    }
+    for (size_t i = mFirstUsedEntry; i < end; ++i) {
         err = eraseEntry(i);
         if (err != ESP_OK) {
             return err;
@@ -428,30 +432,39 @@ esp_err_t Page::mLoadEntryTable()
         // but before the entry state table was altered, the entry locacted via
         // entry state table may actually be half-written.
         // this is easy to check by reading EntryHeader (i.e. first word)
-        uint32_t entryAddress = mBaseAddress + ENTRY_DATA_OFFSET +
-                                static_cast<uint32_t>(mNextFreeEntry) * ENTRY_SIZE;
-        uint32_t header;
-        auto rc = spi_flash_read(entryAddress, &header, sizeof(header));
-        if (rc != ESP_OK) {
-            mState = PageState::INVALID;
-            return rc;
-        }
-        if (header != 0xffffffff) {
-            auto err = alterEntryState(mNextFreeEntry, EntryState::ERASED);
-            if (err != ESP_OK) {
+        if (mNextFreeEntry != INVALID_ENTRY) {
+            uint32_t entryAddress = getEntryAddress(mNextFreeEntry);
+            uint32_t header;
+            auto rc = spi_flash_read(entryAddress, &header, sizeof(header));
+            if (rc != ESP_OK) {
                 mState = PageState::INVALID;
-                return err;
+                return rc;
+            }
+            if (header != 0xffffffff) {
+                auto err = alterEntryState(mNextFreeEntry, EntryState::ERASED);
+                if (err != ESP_OK) {
+                    mState = PageState::INVALID;
+                    return err;
+                }
+                ++mNextFreeEntry;
             }
-            ++mNextFreeEntry;
         }
 
         // check that all variable-length items are written or erased fully
-        for (size_t i = 0; i < mNextFreeEntry; ++i) {
+        Item item;
+        size_t lastItemIndex = INVALID_ENTRY;
+        size_t end = mNextFreeEntry;
+        if (end > ENTRY_COUNT) {
+            end = ENTRY_COUNT;
+        }
+        for (size_t i = 0; i < end; ++i) {
             if (mEntryTable.get(i) == EntryState::ERASED) {
+                lastItemIndex = INVALID_ENTRY;
                 continue;
             }
+            
+            lastItemIndex = i;
 
-            Item item;
             auto err = readEntry(i, item);
             if (err != ESP_OK) {
                 mState = PageState::INVALID;
@@ -476,6 +489,7 @@ esp_err_t Page::mLoadEntryTable()
             for (size_t j = i; j < i + span; ++j) {
                 if (mEntryTable.get(j) != EntryState::WRITTEN) {
                     needErase = true;
+                    lastItemIndex = INVALID_ENTRY;
                     break;
                 }
             }
@@ -484,7 +498,21 @@ esp_err_t Page::mLoadEntryTable()
             }
             i += span - 1;
         }
-
+        
+        // check that last item is not duplicate
+        if (lastItemIndex != INVALID_ENTRY) {
+            size_t findItemIndex = 0;
+            Item dupItem;
+            if (findItem(item.nsIndex, item.datatype, item.key, findItemIndex, dupItem) == ESP_OK) {
+                if (findItemIndex < lastItemIndex) {
+                    auto err = eraseEntryAndSpan(findItemIndex);
+                    if (err != ESP_OK) {
+                        mState = PageState::INVALID;
+                        return err;
+                    }
+                }
+            }
+        }
     }
 
     return ESP_OK;
@@ -551,6 +579,10 @@ esp_err_t Page::findItem(uint8_t nsIndex, ItemType datatype, const char* key, si
     if (mState == PageState::CORRUPT || mState == PageState::INVALID || mState == PageState::UNINITIALIZED) {
         return ESP_ERR_NVS_NOT_FOUND;
     }
+    
+    if (itemIndex >= ENTRY_COUNT) {
+        return ESP_ERR_NVS_NOT_FOUND;
+    }
 
     CachedFindInfo findInfo(nsIndex, datatype, key);
     if (mFindInfo == findInfo) {
@@ -561,9 +593,14 @@ esp_err_t Page::findItem(uint8_t nsIndex, ItemType datatype, const char* key, si
     if (itemIndex > mFirstUsedEntry && itemIndex < ENTRY_COUNT) {
         start = itemIndex;
     }
+    
+    size_t end = mNextFreeEntry;
+    if (end > ENTRY_COUNT) {
+        end = ENTRY_COUNT;
+    }
 
     size_t next;
-    for (size_t i = start; i < mNextFreeEntry; i = next) {
+    for (size_t i = start; i < end; i = next) {
         next = i + 1;
         if (mEntryTable.get(i) != EntryState::WRITTEN) {
             continue;

components/nvs_flash/src/nvs_page.hpp

@@ -40,7 +40,7 @@ public:
 
     bool operator==(const CachedFindInfo& other) const
     {
-        return mKeyPtr == other.mKeyPtr && mType == other.mType && mNsIndex == other.mNsIndex;
+        return mKeyPtr != nullptr && mKeyPtr == other.mKeyPtr && mType == other.mType && mNsIndex == other.mNsIndex;
     }
 
     void setItemIndex(uint32_t index)

components/nvs_flash/src/nvs_pagemanager.cpp

@@ -53,6 +53,58 @@ esp_err_t PageManager::load(uint32_t baseSector, uint32_t sectorCount)
         assert(mPageList.back().getSeqNumber(lastSeqNo) == ESP_OK);
         mSeqNumber = lastSeqNo + 1;
     }
+    
+    // if power went out after a new item for the given key was written,
+    // but before the old one was erased, we end up with a duplicate item
+    Page& lastPage = back();
+    size_t lastItemIndex = SIZE_MAX;
+    Item item;
+    size_t itemIndex = 0;
+    while (lastPage.findItem(Page::NS_ANY, ItemType::ANY, nullptr, itemIndex, item) == ESP_OK) {
+        itemIndex += item.span;
+        lastItemIndex = itemIndex;
+    }
+    
+    if (lastItemIndex != SIZE_MAX) {
+        auto last = PageManager::TPageListIterator(&lastPage);
+        for (auto it = begin(); it != last; ++it) {
+            if (it->eraseItem(item.nsIndex, item.datatype, item.key) == ESP_OK) {
+                break;
+            }
+        }
+    }
+
+    // check if power went out while page was being freed
+    for (auto it = begin(); it!= end(); ++it) {
+        if (it->state() == Page::PageState::FREEING) {
+            Page* newPage = &mPageList.back();
+            if(newPage->state() != Page::PageState::ACTIVE) {
+                auto err = activatePage();
+                if (err != ESP_OK) {
+                    return err;
+                }
+                newPage = &mPageList.back();
+            }
+            while (true) {
+                auto err = it->moveItem(*newPage);
+                if (err == ESP_ERR_NVS_NOT_FOUND) {
+                    break;
+                } else if (err != ESP_OK) {
+                    return err;
+                }
+            }
+            
+            auto err = it->erase();
+            if (err != ESP_OK) {
+                return err;
+            }
+            
+            Page* p = static_cast<Page*>(it);
+            mPageList.erase(it);
+            mFreePageList.push_back(p);
+            break;
+        }
+    }
 
     return ESP_OK;
 }

components/nvs_flash/test/spi_flash_emulation.h

@@ -73,6 +73,10 @@ public:
                 dstAddr + size > mData.size() * 4) {
             return false;
         }
+        
+        if (mFailCountdown != SIZE_T_MAX && mFailCountdown-- == 0) {
+            return false;
+        }
 
         for (size_t i = 0; i < size / 4; ++i) {
             uint32_t sv = src[i];
@@ -103,6 +107,10 @@ public:
             WARN("invalid flash operation detected: erase sector=" << sectorNumber);
             return false;
         }
+        
+        if (mFailCountdown != SIZE_T_MAX && mFailCountdown-- == 0) {
+            return false;
+        }
 
         std::fill_n(begin(mData) + offset, SPI_FLASH_SEC_SIZE / 4, 0xffffffff);
 
@@ -173,6 +181,10 @@ public:
         mLowerSectorBound = lowerSector;
         mUpperSectorBound = upperSector;
     }
+    
+    void failAfter(uint32_t count) {
+        mFailCountdown = count;
+    }
 
 protected:
     static size_t getReadOpTime(uint32_t bytes);
@@ -190,6 +202,8 @@ protected:
     mutable size_t mTotalTime = 0;
     size_t mLowerSectorBound = 0;
     size_t mUpperSectorBound = 0;
+    
+    size_t mFailCountdown = SIZE_T_MAX;
 
 };
 

components/nvs_flash/test/test_nvs.cpp

@@ -153,9 +153,7 @@ TEST_CASE("when page is full, adding an element fails", "[nvs]")
         snprintf(name, sizeof(name), "i%ld", i);
         CHECK(page.writeItem(1, name, i) == ESP_OK);
     }
-    CHECK(page.state() == Page::PageState::FULL);
     CHECK(page.writeItem(1, "foo", 64UL) == ESP_ERR_NVS_PAGE_FULL);
-    CHECK(page.state() == Page::PageState::FULL);
 }
 
 TEST_CASE("page maintains its seq number")
@@ -527,162 +525,194 @@ TEST_CASE("nvs api tests, starting with random data in flash", "[nvs][.][long]")
     }
 }
 
-template<typename TGen>
-esp_err_t doRandomThings(nvs_handle handle, TGen gen, size_t count) {
-    
-    const char* keys[] = {"foo", "bar", "longkey_0123456", "another key", "param1", "param2", "param3", "param4", "param5"};
-    const ItemType types[] = {ItemType::I32, ItemType::I32, ItemType::U64, ItemType::U64, ItemType::SZ, ItemType::SZ, ItemType::SZ, ItemType::SZ, ItemType::SZ};
+extern "C" void nvs_dump();
+
+class RandomTest {
     
+    static const size_t nKeys = 9;
     int32_t v1 = 0, v2 = 0;
     uint64_t v3 = 0, v4 = 0;
-    const size_t strBufLen = 1024;
+    static const size_t strBufLen = 1024;
     char v5[strBufLen], v6[strBufLen], v7[strBufLen], v8[strBufLen], v9[strBufLen];
-    
-    void* values[] = {&v1, &v2, &v3, &v4, &v5, &v6, &v7, &v8, &v9};
-    
-    const size_t nKeys = sizeof(keys) / sizeof(keys[0]);
-    static_assert(nKeys == sizeof(types) / sizeof(types[0]), "");
-    static_assert(nKeys == sizeof(values) / sizeof(values[0]), "");
-    
     bool written[nKeys];
-    std::fill_n(written, nKeys, false);
     
-    auto generateRandomString = [](char* dst, size_t size) {
-        size_t len = 0;
-    };
+public:
+    RandomTest()
+    {
+        std::fill_n(written, nKeys, false);
+    }
+
+    template<typename TGen>
+    esp_err_t doRandomThings(nvs_handle handle, TGen gen, size_t& count) {
     
-    auto randomRead = [&](size_t index) -> esp_err_t {
-        switch (types[index]) {
-            case ItemType::I32:
-            {
-                int32_t val;
-                auto err = nvs_get_i32(handle, keys[index], &val);
-                if (err == ESP_ERR_FLASH_OP_FAIL) {
-                    return err;
-                }
-                if (!written[index]) {
-                    REQUIRE(err == ESP_ERR_NVS_NOT_FOUND);
-                }
-                else {
-                    REQUIRE(val == *reinterpret_cast<int32_t*>(values[index]));
-                }
-                break;
-            }
-                
-            case ItemType::U64:
-            {
-                uint64_t val;
-                auto err = nvs_get_u64(handle, keys[index], &val);
-                if (err == ESP_ERR_FLASH_OP_FAIL) {
-                    return err;
+        const char* keys[] = {"foo", "bar", "longkey_0123456", "another key", "param1", "param2", "param3", "param4", "param5"};
+        const ItemType types[] = {ItemType::I32, ItemType::I32, ItemType::U64, ItemType::U64, ItemType::SZ, ItemType::SZ, ItemType::SZ, ItemType::SZ, ItemType::SZ};
+        
+        void* values[] = {&v1, &v2, &v3, &v4, &v5, &v6, &v7, &v8, &v9};
+        
+        const size_t nKeys = sizeof(keys) / sizeof(keys[0]);
+        static_assert(nKeys == sizeof(types) / sizeof(types[0]), "");
+        static_assert(nKeys == sizeof(values) / sizeof(values[0]), "");
+        
+        
+        auto generateRandomString = [](char* dst, size_t size) {
+            size_t len = 0;
+        };
+        
+        auto randomRead = [&](size_t index) -> esp_err_t {
+            switch (types[index]) {
+                case ItemType::I32:
+                {
+                    int32_t val;
+                    auto err = nvs_get_i32(handle, keys[index], &val);
+                    if (err == ESP_ERR_FLASH_OP_FAIL) {
+                        return err;
+                    }
+                    if (!written[index]) {
+                        REQUIRE(err == ESP_ERR_NVS_NOT_FOUND);
+                    }
+                    else {
+                        REQUIRE(err == ESP_OK);
+                        REQUIRE(val == *reinterpret_cast<int32_t*>(values[index]));
+                    }
+                    break;
                 }
-                if (!written[index]) {
-                    REQUIRE(err == ESP_ERR_NVS_NOT_FOUND);
+                    
+                case ItemType::U64:
+                {
+                    uint64_t val;
+                    auto err = nvs_get_u64(handle, keys[index], &val);
+                    if (err == ESP_ERR_FLASH_OP_FAIL) {
+                        return err;
+                    }
+                    if (!written[index]) {
+                        REQUIRE(err == ESP_ERR_NVS_NOT_FOUND);
+                    }
+                    else {
+                        REQUIRE(err == ESP_OK);
+                        REQUIRE(val == *reinterpret_cast<uint64_t*>(values[index]));
+                    }
+                    break;
                 }
-                else {
-                    REQUIRE(val == *reinterpret_cast<uint64_t*>(values[index]));
+                    
+                case ItemType::SZ:
+                {
+                    char buf[strBufLen];
+                    size_t len = strBufLen;
+                    auto err = nvs_get_str(handle, keys[index], buf, &len);
+                    if (err == ESP_ERR_FLASH_OP_FAIL) {
+                        return err;
+                    }
+                    if (!written[index]) {
+                        REQUIRE(err == ESP_ERR_NVS_NOT_FOUND);
+                    }
+                    else {
+                        REQUIRE(err == ESP_OK);
+                        REQUIRE(strncmp(buf, reinterpret_cast<const char*>(values[index]), strBufLen) == 0);
+                    }
+                    break;
                 }
-                break;
+                    
+                default:
+                    assert(0);
             }
-                
-            case ItemType::SZ:
-            {
-                char buf[strBufLen];
-                size_t len = strBufLen;
-                auto err = nvs_get_str(handle, keys[index], buf, &len);
-                if (err == ESP_ERR_FLASH_OP_FAIL) {
-                    return err;
-                }
-                if (!written[index]) {
-                    REQUIRE(err == ESP_ERR_NVS_NOT_FOUND);
+            return ESP_OK;
+        };
+        
+        auto randomWrite = [&](size_t index) -> esp_err_t {
+            switch (types[index]) {
+                case ItemType::I32:
+                {
+                    int32_t val = static_cast<int32_t>(gen());
+                    
+                    auto err = nvs_set_i32(handle, keys[index], val);
+                    if (err == ESP_ERR_FLASH_OP_FAIL) {
+                        return err;
+                    }
+                    if (err == ESP_ERR_NVS_REMOVE_FAILED) {
+                        written[index] = true;
+                        *reinterpret_cast<int32_t*>(values[index]) = val;
+                        return ESP_ERR_FLASH_OP_FAIL;
+                    }
+                    REQUIRE(err == ESP_OK);
+                    written[index] = true;
+                    *reinterpret_cast<int32_t*>(values[index]) = val;
+                    break;
                 }
-                else {
-                    REQUIRE(strncmp(buf, reinterpret_cast<const char*>(values[index]), strBufLen));
+                    
+                case ItemType::U64:
+                {
+                    uint64_t val = static_cast<uint64_t>(gen());
+                    
+                    auto err = nvs_set_u64(handle, keys[index], val);
+                    if (err == ESP_ERR_FLASH_OP_FAIL) {
+                        return err;
+                    }
+                    if (err == ESP_ERR_NVS_REMOVE_FAILED) {
+                        written[index] = true;
+                        *reinterpret_cast<uint64_t*>(values[index]) = val;
+                        return ESP_ERR_FLASH_OP_FAIL;
+                    }
+                    REQUIRE(err == ESP_OK);
+                    written[index] = true;
+                    *reinterpret_cast<uint64_t*>(values[index]) = val;
+                    break;
                 }
-                break;
-            }
-                
-            default:
-                assert(0);
-        }
-        return ESP_OK;
-    };
-    
-    auto randomWrite = [&](size_t index) -> esp_err_t {
-        switch (types[index]) {
-            case ItemType::I32:
-            {
-                int32_t val = static_cast<int32_t>(gen());
-                *reinterpret_cast<int32_t*>(values[index]) = val;
-                
-                auto err = nvs_set_i32(handle, keys[index], val);
-                if (err == ESP_ERR_FLASH_OP_FAIL) {
-                    return err;
+                    
+                case ItemType::SZ:
+                {
+                    char buf[strBufLen];
+                    size_t len = strBufLen;
+                    
+                    size_t strLen = gen() % (strBufLen - 1);
+                    std::generate_n(buf, strLen, [&]() -> char {
+                        const char c = static_cast<char>(gen() % 127);
+                        return (c < 32) ? 32 : c;
+                    });
+                    buf[strLen] = 0;
+                    
+                    auto err = nvs_set_str(handle, keys[index], buf);
+                    if (err == ESP_ERR_FLASH_OP_FAIL) {
+                        return err;
+                    }
+                    if (err == ESP_ERR_NVS_REMOVE_FAILED) {
+                        written[index] = true;
+                        strlcpy(reinterpret_cast<char*>(values[index]), buf, strBufLen);
+                        return ESP_ERR_FLASH_OP_FAIL;
+                    }
+                    REQUIRE(err == ESP_OK);
+                    written[index] = true;
+                    strlcpy(reinterpret_cast<char*>(values[index]), buf, strBufLen);
+                    break;
                 }
-                REQUIRE(err == ESP_OK);
-                written[index] = true;
-                break;
+                    
+                default:
+                    assert(0);
             }
-                
-            case ItemType::U64:
-            {
-                uint64_t val = static_cast<uint64_t>(gen());
-                *reinterpret_cast<uint64_t*>(values[index]) = val;
-                
-                auto err = nvs_set_u64(handle, keys[index], val);
-                if (err == ESP_ERR_FLASH_OP_FAIL) {
-                    return err;
-                }
-                REQUIRE(err == ESP_OK);
-                written[index] = true;
-                break;
-            }
-                
-            case ItemType::SZ:
-            {
-                char buf[strBufLen];
-                size_t len = strBufLen;
-                
-                size_t strLen = gen() % (strBufLen - 1);
-                std::generate_n(buf, strLen, [&]() -> char {
-                    const char c = static_cast<char>(gen() % 127);
-                    return (c < 32) ? 32 : c;
-                });
-                
-                auto err = nvs_set_str(handle, keys[index], buf);
-                if (err == ESP_ERR_FLASH_OP_FAIL) {
-                    return err;
-                }
-                REQUIRE(err == ESP_OK);
-                written[index] = true;
-                break;
+            return ESP_OK;
+        };
+        
+        
+        for (; count != 0; --count) {
+            size_t index = gen() % nKeys;
+            switch (gen() % 3) {
+                case 0:  // read, 1/3
+                    if (randomRead(index) == ESP_ERR_FLASH_OP_FAIL) {
+                        return ESP_ERR_FLASH_OP_FAIL;
+                    }
+                    break;
+                    
+                default: // write, 2/3
+                    if (randomWrite(index) == ESP_ERR_FLASH_OP_FAIL) {
+                        return ESP_ERR_FLASH_OP_FAIL;
+                    }
+                    break;
             }
-                
-            default:
-                assert(0);
         }
         return ESP_OK;
-    };
-    
-    
-    for (size_t i = 0; i < count; ++i) {
-        size_t index = gen() % nKeys;
-        switch (gen() % 3) {
-            case 0:  // read, 1/3
-                if (randomRead(index) == ESP_ERR_FLASH_OP_FAIL) {
-                    return ESP_ERR_FLASH_OP_FAIL;
-                }
-                break;
-                
-            default: // write, 2/3
-                if (randomWrite(index) == ESP_ERR_FLASH_OP_FAIL) {
-                    return ESP_ERR_FLASH_OP_FAIL;
-                }
-                break;
-        }
     }
-    return ESP_OK;
-}
+};
+
 
 TEST_CASE("monkey test", "[nvs][monkey]")
 {
@@ -693,6 +723,7 @@ TEST_CASE("monkey test", "[nvs][monkey]")
     
     SpiFlashEmulator emu(10);
     emu.randomize(seed);
+    emu.clearStats();
     
     const uint32_t NVS_FLASH_SECTOR = 6;
     const uint32_t NVS_FLASH_SECTOR_COUNT_MIN = 3;
@@ -702,9 +733,66 @@ TEST_CASE("monkey test", "[nvs][monkey]")
     
     nvs_handle handle;
     TEST_ESP_OK(nvs_open("namespace1", NVS_READWRITE, &handle));
+    RandomTest test;
+    size_t count = 1000;
+    CHECK(test.doRandomThings(handle, gen, count) == ESP_OK);
+    
+    s_perf << "Monkey test: nErase=" << emu.getEraseOps() << " nWrite=" << emu.getWriteOps() << std::endl;
+}
 
-    CHECK(doRandomThings(handle, gen, 10000) == ESP_OK);
+TEST_CASE("test recovery from sudden poweroff", "[nvs][recovery]")
+{
+    std::random_device rd;
+    std::mt19937 gen(rd());
+    uint32_t seed = 3;
+    gen.seed(seed);
+    const size_t iter_count = 2000;
+    
+    SpiFlashEmulator emu(10);
+    
+    const uint32_t NVS_FLASH_SECTOR = 6;
+    const uint32_t NVS_FLASH_SECTOR_COUNT_MIN = 3;
+    emu.setBounds(NVS_FLASH_SECTOR, NVS_FLASH_SECTOR + NVS_FLASH_SECTOR_COUNT_MIN);
+    
+    size_t totalOps = 0;
+    int lastPercent = -1;
+    for (uint32_t errDelay = 4; ; ++errDelay) {
+        INFO(errDelay);
+        emu.randomize(seed);
+        emu.clearStats();
+        emu.failAfter(errDelay);
+        RandomTest test;
+        
+        if (totalOps != 0) {
+            int percent = errDelay * 100 / totalOps;
+            if (percent != lastPercent) {
+                printf("%d/%d (%d%%)\r\n", errDelay, static_cast<int>(totalOps), percent);
+                lastPercent = percent;
+            }
+        }
+        
+        TEST_ESP_OK(nvs_flash_init(NVS_FLASH_SECTOR, NVS_FLASH_SECTOR_COUNT_MIN));
 
+        nvs_handle handle;
+        TEST_ESP_OK(nvs_open("namespace1", NVS_READWRITE, &handle));
+        
+        size_t count = iter_count;
+        if(test.doRandomThings(handle, gen, count) != ESP_ERR_FLASH_OP_FAIL) {
+            nvs_close(handle);
+            break;
+        }
+        nvs_close(handle);
+        
+        TEST_ESP_OK(nvs_flash_init(NVS_FLASH_SECTOR, NVS_FLASH_SECTOR_COUNT_MIN));
+        TEST_ESP_OK(nvs_open("namespace1", NVS_READWRITE, &handle));
+        auto res = test.doRandomThings(handle, gen, count);
+        if (res != ESP_OK) {
+            nvs_dump();
+            CHECK(0);
+        }
+        nvs_close(handle);
+        totalOps = emu.getEraseOps() + emu.getWriteOps();
+    }
 }
 
 TEST_CASE("dump all performance data", "[nvs]")