flash: spi_nor: JEDEC ID not always reading correctly

[dan_opito]

Hi,

Our custom hardware makes use of an external flash device, IS25LP032D-JTLE-TR, for storing files (littlefs) and OTA updates. We've noticed, seemingly only after a power-on reset, that we're unable to initiatlise the flash. The error reported is <err> spi_nor: Device id 00 00 00 does not match config 9d 60 16 - but simply hitting the reset button (or detecting -ENODEV from littlefs and rebooting in software) is enough to fix it.

We're rather out-of-date with Zephyr and NCS - we're running SDK 2.2.0, and a Zephyr kernel with a few backports (you can see our tree here: opito-nz/sdk-zephyr: NCS downstream of https://github.com/zephyrproject-rtos/zephyr). I have cherry-picked some interesting looking commits, however none seem to resolve the issue.

I also went through devzone and noticed many with the JEDEC ID error are always seeing this - we only see it after a power-on reset. My theory, then, is something to do with how long Zephyr waits before attempting to talk to the flash. I added a one millisecond delay to spi_nor_configure() without much luck - and no other errors, for example with reading the status register, are reported. I haven't tried probing the data lines to see if there are any bits at all (and SPI is misreading) - but probing this design will be challenging as I need to solder to the USON package (i.e. similar to QFN).

I tried increasing t-enter-dpd and t-exit-dpd (from 3 us to 30 us) with no change.

We're about to get another batch of devices, with the nRF9151, and are using the same flash device. My work around for now is detecting the -ENODEV and rebooting our firmware. It's inelegant but it seems to work.

Kind regards,

Dan

[dan_opito]

I've just had some success, using k_busy_wait(). Firstly, here's my code from spi_nor_configure():

static int spi_nor_configure(const struct device *dev)
{

    /* ... removed ... */

    /* now the spi bus is configured, we can verify SPI
     * connectivity by reading the JEDEC ID.
     */

    rc = spi_nor_read_jedec_id(dev, jedec_id);
    if (rc != 0) {
        LOG_ERR("JEDEC ID read failed: %d", rc);
        return -ENODEV;
    }
    LOG_INF("JEDEC: %02x %02x %02x", jedec_id[0], jedec_id[1], jedec_id[2]);
    k_busy_wait(100000);

    rc = spi_nor_read_jedec_id(dev, jedec_id);
    if (rc != 0) {
        LOG_ERR("JEDEC ID read failed: %d", rc);
        return -ENODEV;
    }
    LOG_INF("JEDEC: %02x %02x %02x", jedec_id[0], jedec_id[1], jedec_id[2]);
    k_busy_wait(100000);

    rc = spi_nor_read_jedec_id(dev, jedec_id);
    if (rc != 0) {
        LOG_ERR("JEDEC ID read failed: %d", rc);
        return -ENODEV;
    }
    LOG_INF("JEDEC: %02x %02x %02x", jedec_id[0], jedec_id[1], jedec_id[2]);
    k_busy_wait(100000);

    rc = spi_nor_read_jedec_id(dev, jedec_id);
    if (rc != 0) {
        LOG_ERR("JEDEC ID read failed: %d", rc);
        return -ENODEV;
    }

#ifndef CONFIG_SPI_NOR_SFDP_RUNTIME
    /* For minimal and devicetree we need to check the JEDEC ID
     * against the one from devicetree, to ensure we didn't find a
     * device that has different parameters.
     */

    if (memcmp(jedec_id, cfg->jedec_id, sizeof(jedec_id)) != 0) {
        LOG_ERR("Device id %02x %02x %02x does not match config %02x %02x %02x",
            jedec_id[0], jedec_id[1], jedec_id[2],
            cfg->jedec_id[0], cfg->jedec_id[1], cfg->jedec_id[2]);
        return -EINVAL;
    }
#endif

    /* ... removed ... */
}

... and here's the log output!

[00:00:00.492,858] <inf> spi_nor: JEDEC: 00 00 00
[00:00:00.595,214] <inf> spi_nor: JEDEC: 9d 60 16
[00:00:00.697,540] <inf> spi_nor: JEDEC: 9d 60 16

I consider this a breakthrough, as it reallly demonstrates the power-on delay. Here's with the same code, but after a software reset:

[00:00:00.493,041] <inf> spi_nor: JEDEC: 9d 60 16
[00:00:00.595,458] <inf> spi_nor: JEDEC: 9d 60 16
[00:00:00.697,845] <inf> spi_nor: JEDEC: 9d 60 16

Initially I was using k_sleep(), but I'm not sure if I can even pause that thread and perhaps the return code would have showed a zero delay. In any case, a blocking delay seems to fix it. I'll continue to experiment, but I'd love to hear comments from someone more experienced.

[dan_opito]

I've implemented retries in the short term, like so: flash: spi_nor: add retry when JEDEC ID does not match · opito-nz/sdk-zephyr@c99a204 (github.com)

[Menon]

Hello,

If introducing a blocking delay, such as k_busy_wait(), resolves the initialization issue for your external flash device, it suggests that the flash device indeed needs additional time to be ready after a power-on reset. k_sleep(): This function puts the calling thread to sleep for a specified duration. During this sleep period, the CPU can perform other tasks, making it a non-blocking delay.k_busy_wait(): This function creates a blocking delay where the CPU is actively waiting for the specified duration, and it doesn't perform other tasks during this period.

I will look into your implementation.

Kind Regards,

Abhijith