Mbed-os: kvstore-general_tests_phase_1 fails on CY8CPROTO_062_4343W after #11918

[kyle-cypress]

Description of defect

SEC_kvstore_init fails in features-storage-tests-kvstore-general_tests_phase_1 on CY8CPROTO_062_4343W (and possibly other Cypress targets as well; those have not been tested yet).
A bisect narrowed the culprit to the test updates in abbb2485d222f0e2d8d1140b9697db8703fdf25b (merged as part of #11918). If that commit is reverted the tests all pass.
Further experimentation narrowed the cause specifically to the following portion of the patch:

-        erase_size  = sec_bd->get_erase_size();
-        ul_bd_size  = erase_size * 4;
-        rbp_bd_size = erase_size * 2;
+        res = sec_bd->deinit();
+        TEST_ASSERT_EQUAL_ERROR_CODE(MBED_SUCCESS, res);

Target(s) affected by this defect ?

CY8CPROTO_062_4343W (possibly others as well).

Toolchain(s) (name and version) displaying this defect ?

GCC_ARM 6.3.1

What version of Mbed-os are you using (tag or sha) ?

9248169f1f008a6550cbf725f9d5c91e68c28f3c

What version(s) of tools are you using. List all that apply (E.g. mbed-cli)

mbed-cli version 1.10.1

How is this defect reproduced ?

Run features-storage-tests-kvstore-general_tests_phase_1 on CY8CPROTO_062_4343W

Relevant log snippet with verbose mode (mbed test -vv) enabled:

1575504702.34][CONN][RXD] >>> Running case #75: 'SEC_kvstore_init'...
[1575504702.38][CONN][RXD]
[1575504702.38][CONN][RXD]
[1575504702.39][CONN][INF] found KV pair in stream: {{__testcase_start;SEC_kvstore_init}}, queued...
[1575504702.40][CONN][RXD] ++ MbedOS Error Info ++
[1575504702.46][CONN][RXD] Error Status: 0x80FF011B Code: 283 Module: 255
[1575504702.51][CONN][RXD] Error Message: TDBSTORE: Unable to read record at init
[1575504702.54][CONN][RXD] Location: 0x100115F7
[1575504702.55][CONN][RXD] Error Value: 0x0
[1575504702.66][CONN][RXD] Current Thread: main Id: 0x8004540 Entry: 0x100137BD StackSize: 0x1000 StackMem: 0x80053E0 SP: 0x800617C
[1575504702.75][CONN][RXD] For more info, visit: https://mbed.com/s/error?error=0x80FF011B&tgt=CY8CPROTO_062_4343W
[1575504702.77][CONN][RXD] -- MbedOS Error Info --

[ciarmcom]

Internal Jira reference: https://jira.arm.com/browse/MBOTRIAGE-2451

[0xc0170]

cc @ARMmbed/mbed-os-storage

[SeppoTakalo]

        // Check validity of master record
        master_record_data_t master_rec;
        ret = read_record(area, _master_record_offset, const_cast<char *>(master_rec_key),
                          &master_rec, sizeof(master_rec), actual_data_size, 0, false, true, true, false,
                          hash, flags, next_offset);
        if ((ret != MBED_SUCCESS) && (ret != MBED_ERROR_INVALID_DATA_DETECTED)) {
            MBED_ERROR(ret, "TDBSTORE: Unable to read record at init");
        }

That piece of code is last changed a year ago.
So this needs to be invested whether it is actually a device error.

[SeppoTakalo]

I can replicate the issue with current Mbed OS master. I'll continue to investigate.
As the broken commit is the one that fixed SlicingBlockDevice sizes, I assume that this has something to do with either storage itself, or then TDBStore cannot initialize itself on empty or broken storage.

[SeppoTakalo]

[DBG ][QSPIF]: QSPIFBlockDevice csel: 720898
[DBG ][QSPIF]: QSPIFBlockDevice csel: 720898
[DBG ][QSPIF]: QSPIFBlockDevice csel: 720898
[DBG ][QSPIF]: Read Inst: 0xebh
[DBG ][QSPIF]: Inst: 0xebh, addr: 512, size: 24
[DBG ][QSPIF]: Read Inst: 0xebh
[DBG ][QSPIF]: Inst: 0xebh, addr: 1024, size: 4
[DBG ][QSPIF]: Read Inst: 0xebh
[DBG ][QSPIF]: Inst: 0xebh, addr: 1028, size: 8
[ERR ][TDBStore]: read_record() returned -2130771685

-2130771685 & 0xffff = 283 which is error: /* 283 Read failed */

[kyle-cypress]

I looked into this a bit today I believe the problem is that the new sizes are too small - they may not span two erase sectors. For example, in the external flash on CY8CPROTO_062_4343W, the erase size is 0x40000 and the program size is 0x200 - so program_size * 40 = 0x5000 which gets aligned up to exactly one erase sector. The "Read failed" is reported because it is trying to read past the end of the second area, whose size in TDBStore::_area_params is computed as 0.
(aside: can/should TDBStore::calc_area_params throw an error in cases like this?)
I suggest aligning the sizes to erase_size * 2 so that garbage collection is guaranteed to work correctly, i.e.:

        ul_bd_size  = align_up(program_size * 40, erase_size * 2);
        rbp_bd_size = align_up(program_size * 40, erase_size * 2);

[SeppoTakalo]

@kyle-cypress Thanks, that seems to be the root cause.

That fixed the CY8PROTO. I'll just verify with K64F and send a patch if it does not cause regression.