qspi_nor: Failed to schedule device sleep: -16

[robsrick]

Hi

I'm using nrf toolchain/sdk 2.5.2.

Got a strange problem with my QSPI NOR flash interface.  when i run flash_erase i get error message "qspi_nor: Failed to schedule device sleep: -16" pretty much immediately. but the flash does seem to erase correctly.

in func qspi_erase() in nrf_qspi_nor.c if i put a breakpoint on ln689 which calls qspi_device_uninit(dev) and wait for 20+ seconds i do not receive the error. This corresponds roughly with whole long a full flash erase takes for my mx25r0835f flash chip. It looks like the qspi drivers aren't waiting for the flash to actually erase before deinit?

qspi_wait_for_completion returns immediately if that is relevant?

Any idea how i can resolve this issue?

Regards

Robert

call to flash_erase, where flash_dev points to the dts device below, address=0 and size = 1048576

return flash_erase(flash_dev, address, size);

Relevant section of my dts:

&qspi {

    compatible= "nordic,nrf-qspi";

    status = "okay";

    pinctrl-0 = <&qspi_default>;

    pinctrl-1 = <&qspi_sleep>;

    pinctrl-names = "default", "sleep";

    mx25r08: mx25r0835f@0 {

        compatible = "nordic,qspi-nor";

        reg = <0>;

        sck-frequency = <50000000>;

        jedec-id = [ c2 28 14  ];

        size = <0x0800000>; /* flash capacity in bits */

        has-dpd;

        t-enter-dpd = <10000>;

        t-exit-dpd = <35000>;

    };

};

[Sigurd Hellesvik]

Hi,

You can see this with a simple sample where you only write/erase from external flash, right?

Do you have a nRF52840DK?
If so, can you test the same code on the nRF52840DK, to see if you see the same error on that?
It would be useful to test if the error is related to the specific external flash or the firmware.

Regards,
Sigurd Hellesvik

[robsrick]

Hi,

Using a DK with the built in flash does not result in this error so it seems to be linked to the flash chip I've got on my custom board.

The test code i've got set up is simply erasing and writing to the flash in a single thread.

Regards

Robert

[Sigurd Hellesvik]

Hi Rob,

robsrick said:

v2.6.0\zephyr\drivers\flash\nrf_qspi_nor.c

There is a bug in this driver in v2.6.0 we are looking into internally.
I do not know if it is the same you refer to here, but we should fix the one I mention first.
I will let you know when a PR is released for this, so you can see what it is about

[Sigurd Hellesvik]

Sigurd Hellesvik said:

I will let you know when a PR is released for this, so you can see what it is about

No PR yet, but the issue is explained at  spi_flash is not running on nRF5340DK out of box 

But as you can see, one the external flash works, it should continue working so I do not think it is related to what you see. So let's have a look at this ticket as is then

[Sigurd Hellesvik]

Reading through your newest comment I dont quite understand, and I think it is because it is so long since I last looked at this ticket.

Could you explain what the bug you are trying to fix is again?
There are so many comments here so it would be good if I do not have to read and understand it all again

[robsrick]

basically, erasing my external flash on qspi takes like 20-30 seconds according to the datasheet but the SDK doesn't actually wait, it just returns instantly. this puts it in a bad state where it becomes unresponsive when the SDK is expecting it to respond and the only way i can fix it is either sticking a breakpoint before qspi_wait_for_completion(dev, res); or sleeping for sometime before then.

[Sigurd Hellesvik]

One of our developers comments from previously goes like:
"We should probably disallow erasing devices by chunks larger than page, because in multithreaded env, and especially when XIP is used, requesting larger chunk to be erased at once makes device inoperative for [ms ]to even [S], which willl probably make CPU inoperative for a quite a moment."

And you are erasing a large chunk at once right.

I hope I have not already suggested this: But have you concidered erasing one page at a time instead of all at once with one command? Then you can loop that for the whole flash and call a small k_sleep() inbetween each loop to yield for possible other parts of the RTOS to run in the meantime.

[robsrick]

Hi Sigurd

Have tried sector erase as suggested. First i did some profiling using a customised qspi_erase as shown below. each line i've added has comment //customised

/* QSPI erase */
static int qspi_erase(const struct device *dev, uint32_t addr, uint32_t size)
{
	const struct qspi_nor_config *params = dev->config;
	int rc, rc2;
	int64_t time_stamp = 0; //customised
	int64_t erase_duration = 0; //customised
	int64_t post_erase_wait_duration = 0; //customised

	rc = qspi_nor_write_protection_set(dev, false);
	if (rc != 0) {
		return rc;
	}
	while (size > 0) {
		nrfx_err_t res = !NRFX_SUCCESS;
		uint32_t adj = 0;

		if (size == params->size) {
			/* chip erase */
			res = nrfx_qspi_chip_erase();
			adj = size;
		} else if ((size >= QSPI_BLOCK_SIZE) &&
			   QSPI_IS_BLOCK_ALIGNED(addr)) {
			/* 64 kB block erase */
			res = nrfx_qspi_erase(NRF_QSPI_ERASE_LEN_64KB, addr);
			adj = QSPI_BLOCK_SIZE;
		} else if ((size >= QSPI_SECTOR_SIZE) &&
			   QSPI_IS_SECTOR_ALIGNED(addr)) {
			/* 4kB sector erase */
			time_stamp = k_uptime_get(); //customised
			res = nrfx_qspi_erase(NRF_QSPI_ERASE_LEN_4KB, addr);
			erase_duration = k_uptime_delta(&time_stamp); //customised
			adj = QSPI_SECTOR_SIZE;
		} else {
			/* minimal erase size is at least a sector size */
			LOG_ERR("unsupported at 0x%lx size %zu", (long)addr, size);
			res = NRFX_ERROR_INVALID_PARAM;
		}

		//k_sleep(K_MSEC(20000)); //customised
		qspi_wait_for_completion(dev, res);
		post_erase_wait_duration = k_uptime_delta(&time_stamp); //customised
		if (res == NRFX_SUCCESS) {
			addr += adj;
			size -= adj;
		} else {
			LOG_ERR("erase error at 0x%lx size %zu", (long)addr, size);
			rc = qspi_get_zephyr_ret_code(res);
			break; 
		}
	}

	LOG_INF("Erase duration=%llims, Post erase Wait Duration=%llims",erase_duration,post_erase_wait_duration);  //customised

	rc2 = qspi_nor_write_protection_set(dev, true);

	return rc != 0 ? rc : rc2;
}

here's the resulting log. you can see the first erase the wait time post erase is 0ms and every subsequent wait is 80ms. I get an error where for the first sector, in the case it does not seem to wait, pm_device_runtime_put fails.

the implication seems to be that when i go to write to the flash after doing a full erase the flash_write returns err -5, which is an I/O Error according to Zephyr docs.

[00:00:02.158,172] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=0ms
[00:00:02.158,264] <err> qspi_nor: pm_device_runtime_put failed: -16
[00:00:02.158,264] <inf> nept_flog: Flog_Format: Erased sector 0 (addr=0)
[00:00:02.244,140] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:02.244,201] <inf> nept_flog: Flog_Format: Erased sector 1 (addr=4096)
[00:00:02.335,052] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=91ms
[00:00:02.335,113] <inf> nept_flog: Flog_Format: Erased sector 2 (addr=8192)
[00:00:02.419,647] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:02.419,708] <inf> nept_flog: Flog_Format: Erased sector 3 (addr=12288)
[00:00:02.508,575] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:02.508,636] <inf> nept_flog: Flog_Format: Erased sector 4 (addr=16384)
[00:00:02.597,503] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:02.597,564] <inf> nept_flog: Flog_Format: Erased sector 5 (addr=20480)
[00:00:02.682,678] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:02.682,739] <inf> nept_flog: Flog_Format: Erased sector 6 (addr=24576)
[00:00:02.767,791] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:02.767,852] <inf> nept_flog: Flog_Format: Erased sector 7 (addr=28672)
[00:00:02.862,945] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=95ms
[00:00:02.863,006] <inf> nept_flog: Flog_Format: Erased sector 8 (addr=32768)
[00:00:02.948,913] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:02.948,974] <inf> nept_flog: Flog_Format: Erased sector 9 (addr=36864)
[00:00:03.039,184] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:03.039,215] <inf> nept_flog: Flog_Format: Erased sector 10 (addr=40960)
[00:00:03.128,540] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:03.128,601] <inf> nept_flog: Flog_Format: Erased sector 11 (addr=45056)
[00:00:03.214,294] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:03.214,355] <inf> nept_flog: Flog_Format: Erased sector 12 (addr=49152)
[00:00:03.299,713] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:03.299,774] <inf> nept_flog: Flog_Format: Erased sector 13 (addr=53248)
[00:00:03.392,547] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=93ms
[00:00:03.392,578] <inf> nept_flog: Flog_Format: Erased sector 14 (addr=57344)
[00:00:03.477,722] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:03.477,752] <inf> nept_flog: Flog_Format: Erased sector 15 (addr=61440)
[00:00:03.560,577] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:03.560,638] <inf> nept_flog: Flog_Format: Erased sector 16 (addr=65536)
[00:00:03.647,247] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=87ms
[00:00:03.647,308] <inf> nept_flog: Flog_Format: Erased sector 17 (addr=69632)
[00:00:03.739,227] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=92ms
[00:00:03.739,288] <inf> nept_flog: Flog_Format: Erased sector 18 (addr=73728)
[00:00:03.828,002] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:03.828,063] <inf> nept_flog: Flog_Format: Erased sector 19 (addr=77824)
[00:00:03.922,790] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=94ms
[00:00:03.922,821] <inf> nept_flog: Flog_Format: Erased sector 20 (addr=81920)
[00:00:04.007,965] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:04.008,026] <inf> nept_flog: Flog_Format: Erased sector 21 (addr=86016)
[00:00:04.093,292] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:04.093,353] <inf> nept_flog: Flog_Format: Erased sector 22 (addr=90112)
[00:00:04.189,514] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=96ms
[00:00:04.189,544] <inf> nept_flog: Flog_Format: Erased sector 23 (addr=94208)
[00:00:04.269,989] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:04.270,019] <inf> nept_flog: Flog_Format: Erased sector 24 (addr=98304)
[00:00:04.356,079] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:04.356,140] <inf> nept_flog: Flog_Format: Erased sector 25 (addr=102400)
[00:00:04.442,230] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:04.442,291] <inf> nept_flog: Flog_Format: Erased sector 26 (addr=106496)
[00:00:04.528,381] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:04.528,442] <inf> nept_flog: Flog_Format: Erased sector 27 (addr=110592)
[00:00:04.613,983] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:04.614,044] <inf> nept_flog: Flog_Format: Erased sector 28 (addr=114688)
[00:00:04.706,665] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=92ms
[00:00:04.706,726] <inf> nept_flog: Flog_Format: Erased sector 29 (addr=118784)
[00:00:04.792,724] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:04.792,755] <inf> nept_flog: Flog_Format: Erased sector 30 (addr=122880)
[00:00:04.881,622] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:04.881,683] <inf> nept_flog: Flog_Format: Erased sector 31 (addr=126976)
[00:00:04.964,111] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:04.964,172] <inf> nept_flog: Flog_Format: Erased sector 32 (addr=131072)
[00:00:05.051,116] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=87ms
[00:00:05.051,147] <inf> nept_flog: Flog_Format: Erased sector 33 (addr=135168)
[00:00:05.138,793] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=87ms
[00:00:05.138,854] <inf> nept_flog: Flog_Format: Erased sector 34 (addr=139264)
[00:00:05.227,844] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:05.227,874] <inf> nept_flog: Flog_Format: Erased sector 35 (addr=143360)
[00:00:05.307,189] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:05.307,250] <inf> nept_flog: Flog_Format: Erased sector 36 (addr=147456)
[00:00:05.392,608] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:05.392,669] <inf> nept_flog: Flog_Format: Erased sector 37 (addr=151552)
[00:00:05.481,597] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:05.481,658] <inf> nept_flog: Flog_Format: Erased sector 38 (addr=155648)
[00:00:05.566,802] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:05.566,833] <inf> nept_flog: Flog_Format: Erased sector 39 (addr=159744)
[00:00:05.651,245] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:05.651,275] <inf> nept_flog: Flog_Format: Erased sector 40 (addr=163840)
[00:00:05.737,548] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:05.737,609] <inf> nept_flog: Flog_Format: Erased sector 41 (addr=167936)
[00:00:05.820,098] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:05.820,190] <inf> nept_flog: Flog_Format: Erased sector 42 (addr=172032)
[00:00:05.914,154] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=94ms
[00:00:05.914,215] <inf> nept_flog: Flog_Format: Erased sector 43 (addr=176128)
[00:00:05.994,415] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:05.994,476] <inf> nept_flog: Flog_Format: Erased sector 44 (addr=180224)
[00:00:06.080,169] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:06.080,200] <inf> nept_flog: Flog_Format: Erased sector 45 (addr=184320)
[00:00:06.166,107] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:06.166,137] <inf> nept_flog: Flog_Format: Erased sector 46 (addr=188416)
[00:00:06.251,464] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:06.251,525] <inf> nept_flog: Flog_Format: Erased sector 47 (addr=192512)
[00:00:06.330,596] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=79ms
[00:00:06.330,627] <inf> nept_flog: Flog_Format: Erased sector 48 (addr=196608)
[00:00:06.418,151] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=88ms
[00:00:06.418,182] <inf> nept_flog: Flog_Format: Erased sector 49 (addr=200704)
[00:00:06.500,976] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=82ms
[00:00:06.501,007] <inf> nept_flog: Flog_Format: Erased sector 50 (addr=204800)
[00:00:06.586,639] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:06.586,669] <inf> nept_flog: Flog_Format: Erased sector 51 (addr=208896)
[00:00:06.670,135] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:06.670,196] <inf> nept_flog: Flog_Format: Erased sector 52 (addr=212992)
[00:00:06.759,613] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:06.759,643] <inf> nept_flog: Flog_Format: Erased sector 53 (addr=217088)
[00:00:06.846,405] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=87ms
[00:00:06.846,466] <inf> nept_flog: Flog_Format: Erased sector 54 (addr=221184)
[00:00:06.939,697] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=93ms
[00:00:06.939,758] <inf> nept_flog: Flog_Format: Erased sector 55 (addr=225280)
[00:00:07.020,141] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:07.020,202] <inf> nept_flog: Flog_Format: Erased sector 56 (addr=229376)
[00:00:07.106,689] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:07.106,750] <inf> nept_flog: Flog_Format: Erased sector 57 (addr=233472)
[00:00:07.191,314] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:07.191,345] <inf> nept_flog: Flog_Format: Erased sector 58 (addr=237568)
[00:00:07.281,433] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:07.281,463] <inf> nept_flog: Flog_Format: Erased sector 59 (addr=241664)
[00:00:07.362,060] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:07.362,121] <inf> nept_flog: Flog_Format: Erased sector 60 (addr=245760)
[00:00:07.451,904] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:07.451,934] <inf> nept_flog: Flog_Format: Erased sector 61 (addr=249856)
[00:00:07.536,193] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:07.536,254] <inf> nept_flog: Flog_Format: Erased sector 62 (addr=253952)
[00:00:07.621,582] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:07.621,643] <inf> nept_flog: Flog_Format: Erased sector 63 (addr=258048)
[00:00:07.700,683] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=79ms
[00:00:07.700,714] <inf> nept_flog: Flog_Format: Erased sector 64 (addr=262144)
[00:00:07.788,452] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=88ms
[00:00:07.788,482] <inf> nept_flog: Flog_Format: Erased sector 65 (addr=266240)
[00:00:07.871,002] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=82ms
[00:00:07.871,032] <inf> nept_flog: Flog_Format: Erased sector 66 (addr=270336)
[00:00:07.956,512] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:07.956,604] <inf> nept_flog: Flog_Format: Erased sector 67 (addr=274432)
[00:00:08.040,283] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:08.040,344] <inf> nept_flog: Flog_Format: Erased sector 68 (addr=278528)
[00:00:08.125,762] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:08.125,823] <inf> nept_flog: Flog_Format: Erased sector 69 (addr=282624)
[00:00:08.205,688] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:08.205,749] <inf> nept_flog: Flog_Format: Erased sector 70 (addr=286720)
[00:00:08.300,537] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=95ms
[00:00:08.300,598] <inf> nept_flog: Flog_Format: Erased sector 71 (addr=290816)
[00:00:08.381,195] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:08.381,256] <inf> nept_flog: Flog_Format: Erased sector 72 (addr=294912)
[00:00:08.464,447] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:08.464,508] <inf> nept_flog: Flog_Format: Erased sector 73 (addr=299008)
[00:00:08.548,797] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:08.548,858] <inf> nept_flog: Flog_Format: Erased sector 74 (addr=303104)
[00:00:08.638,488] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:08.638,519] <inf> nept_flog: Flog_Format: Erased sector 75 (addr=307200)
[00:00:08.723,205] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:08.723,266] <inf> nept_flog: Flog_Format: Erased sector 76 (addr=311296)
[00:00:08.812,469] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:08.812,530] <inf> nept_flog: Flog_Format: Erased sector 77 (addr=315392)
[00:00:08.896,087] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:08.896,118] <inf> nept_flog: Flog_Format: Erased sector 78 (addr=319488)
[00:00:08.981,323] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:08.981,384] <inf> nept_flog: Flog_Format: Erased sector 79 (addr=323584)
[00:00:09.063,385] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=82ms
[00:00:09.063,415] <inf> nept_flog: Flog_Format: Erased sector 80 (addr=327680)
[00:00:09.154,876] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=91ms
[00:00:09.154,937] <inf> nept_flog: Flog_Format: Erased sector 81 (addr=331776)
[00:00:09.237,609] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:09.237,670] <inf> nept_flog: Flog_Format: Erased sector 82 (addr=335872)
[00:00:09.327,087] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:09.327,117] <inf> nept_flog: Flog_Format: Erased sector 83 (addr=339968)
[00:00:09.411,102] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:09.411,163] <inf> nept_flog: Flog_Format: Erased sector 84 (addr=344064)
[00:00:09.495,056] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:09.495,086] <inf> nept_flog: Flog_Format: Erased sector 85 (addr=348160)
[00:00:09.578,704] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:09.578,735] <inf> nept_flog: Flog_Format: Erased sector 86 (addr=352256)
[00:00:09.665,161] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=87ms
[00:00:09.665,222] <inf> nept_flog: Flog_Format: Erased sector 87 (addr=356352)
[00:00:09.749,786] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:09.749,816] <inf> nept_flog: Flog_Format: Erased sector 88 (addr=360448)
[00:00:09.830,078] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:09.830,139] <inf> nept_flog: Flog_Format: Erased sector 89 (addr=364544)
[00:00:09.914,703] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:09.914,764] <inf> nept_flog: Flog_Format: Erased sector 90 (addr=368640)
[00:00:10.000,488] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:10.000,518] <inf> nept_flog: Flog_Format: Erased sector 91 (addr=372736)
[00:00:10.084,289] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:10.084,350] <inf> nept_flog: Flog_Format: Erased sector 92 (addr=376832)
[00:00:10.165,405] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:10.165,466] <inf> nept_flog: Flog_Format: Erased sector 93 (addr=380928)
[00:00:10.245,391] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:10.245,422] <inf> nept_flog: Flog_Format: Erased sector 94 (addr=385024)
[00:00:10.334,136] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:10.334,167] <inf> nept_flog: Flog_Format: Erased sector 95 (addr=389120)
[00:00:10.416,107] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=82ms
[00:00:10.416,168] <inf> nept_flog: Flog_Format: Erased sector 96 (addr=393216)
[00:00:10.502,075] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:10.502,136] <inf> nept_flog: Flog_Format: Erased sector 97 (addr=397312)
[00:00:10.582,000] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:10.582,061] <inf> nept_flog: Flog_Format: Erased sector 98 (addr=401408)
[00:00:10.670,410] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=88ms
[00:00:10.670,440] <inf> nept_flog: Flog_Format: Erased sector 99 (addr=405504)
[00:00:10.750,213] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:10.750,274] <inf> nept_flog: Flog_Format: Erased sector 100 (addr=409600)
[00:00:10.838,195] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=88ms
[00:00:10.838,256] <inf> nept_flog: Flog_Format: Erased sector 101 (addr=413696)
[00:00:10.918,060] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:10.918,151] <inf> nept_flog: Flog_Format: Erased sector 102 (addr=417792)
[00:00:11.004,028] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:11.004,058] <inf> nept_flog: Flog_Format: Erased sector 103 (addr=421888)
[00:00:11.088,714] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:11.088,745] <inf> nept_flog: Flog_Format: Erased sector 104 (addr=425984)
[00:00:11.173,675] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:11.173,736] <inf> nept_flog: Flog_Format: Erased sector 105 (addr=430080)
[00:00:11.254,516] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:11.254,577] <inf> nept_flog: Flog_Format: Erased sector 106 (addr=434176)
[00:00:11.340,545] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:11.340,606] <inf> nept_flog: Flog_Format: Erased sector 107 (addr=438272)
[00:00:11.420,593] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:11.420,623] <inf> nept_flog: Flog_Format: Erased sector 108 (addr=442368)
[00:00:11.500,488] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:11.500,518] <inf> nept_flog: Flog_Format: Erased sector 109 (addr=446464)
[00:00:11.583,862] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:11.583,923] <inf> nept_flog: Flog_Format: Erased sector 110 (addr=450560)
[00:00:11.673,065] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:11.673,095] <inf> nept_flog: Flog_Format: Erased sector 111 (addr=454656)
[00:00:11.755,126] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=82ms
[00:00:11.755,187] <inf> nept_flog: Flog_Format: Erased sector 112 (addr=458752)
[00:00:11.837,646] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=82ms
[00:00:11.837,677] <inf> nept_flog: Flog_Format: Erased sector 113 (addr=462848)
[00:00:11.925,140] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=88ms
[00:00:11.925,201] <inf> nept_flog: Flog_Format: Erased sector 114 (addr=466944)
[00:00:12.012,847] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=87ms
[00:00:12.012,878] <inf> nept_flog: Flog_Format: Erased sector 115 (addr=471040)
[00:00:12.096,282] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:12.096,343] <inf> nept_flog: Flog_Format: Erased sector 116 (addr=475136)
[00:00:12.176,269] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:12.176,330] <inf> nept_flog: Flog_Format: Erased sector 117 (addr=479232)
[00:00:12.259,735] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:12.259,796] <inf> nept_flog: Flog_Format: Erased sector 118 (addr=483328)
[00:00:12.343,383] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:12.343,444] <inf> nept_flog: Flog_Format: Erased sector 119 (addr=487424)
[00:00:12.428,131] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:12.428,192] <inf> nept_flog: Flog_Format: Erased sector 120 (addr=491520)
[00:00:12.512,542] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:12.512,573] <inf> nept_flog: Flog_Format: Erased sector 121 (addr=495616)
[00:00:12.596,649] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:12.596,710] <inf> nept_flog: Flog_Format: Erased sector 122 (addr=499712)
[00:00:12.676,818] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:12.676,879] <inf> nept_flog: Flog_Format: Erased sector 123 (addr=503808)
[00:00:12.756,744] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:12.756,805] <inf> nept_flog: Flog_Format: Erased sector 124 (addr=507904)
[00:00:12.840,728] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:12.840,789] <inf> nept_flog: Flog_Format: Erased sector 125 (addr=512000)
[00:00:12.924,133] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:12.924,194] <inf> nept_flog: Flog_Format: Erased sector 126 (addr=516096)
[00:00:13.006,896] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=82ms
[00:00:13.006,988] <inf> nept_flog: Flog_Format: Erased sector 127 (addr=520192)
[00:00:13.088,684] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:13.088,745] <inf> nept_flog: Flog_Format: Erased sector 128 (addr=524288)
[00:00:13.175,323] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=87ms
[00:00:13.175,384] <inf> nept_flog: Flog_Format: Erased sector 129 (addr=528384)
[00:00:13.260,498] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:13.260,559] <inf> nept_flog: Flog_Format: Erased sector 130 (addr=532480)
[00:00:13.346,282] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:13.346,343] <inf> nept_flog: Flog_Format: Erased sector 131 (addr=536576)
[00:00:13.436,492] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:13.436,553] <inf> nept_flog: Flog_Format: Erased sector 132 (addr=540672)
[00:00:13.522,521] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:13.522,552] <inf> nept_flog: Flog_Format: Erased sector 133 (addr=544768)
[00:00:13.608,398] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:13.608,428] <inf> nept_flog: Flog_Format: Erased sector 134 (addr=548864)
[00:00:13.694,335] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:13.694,396] <inf> nept_flog: Flog_Format: Erased sector 135 (addr=552960)
[00:00:13.781,829] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=87ms
[00:00:13.781,890] <inf> nept_flog: Flog_Format: Erased sector 136 (addr=557056)
[00:00:13.871,673] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:13.871,734] <inf> nept_flog: Flog_Format: Erased sector 137 (addr=561152)
[00:00:13.957,916] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:13.957,946] <inf> nept_flog: Flog_Format: Erased sector 138 (addr=565248)
[00:00:14.043,914] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:14.043,975] <inf> nept_flog: Flog_Format: Erased sector 139 (addr=569344)
[00:00:14.130,249] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:14.130,279] <inf> nept_flog: Flog_Format: Erased sector 140 (addr=573440)
[00:00:14.216,369] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:14.216,400] <inf> nept_flog: Flog_Format: Erased sector 141 (addr=577536)
[00:00:14.302,154] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:14.302,215] <inf> nept_flog: Flog_Format: Erased sector 142 (addr=581632)
[00:00:14.395,751] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=93ms
[00:00:14.395,782] <inf> nept_flog: Flog_Format: Erased sector 143 (addr=585728)
[00:00:14.475,219] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:14.475,250] <inf> nept_flog: Flog_Format: Erased sector 144 (addr=589824)
[00:00:14.565,338] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:14.565,368] <inf> nept_flog: Flog_Format: Erased sector 145 (addr=593920)
[00:00:14.650,573] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:14.650,604] <inf> nept_flog: Flog_Format: Erased sector 146 (addr=598016)
[00:00:14.735,900] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:14.735,961] <inf> nept_flog: Flog_Format: Erased sector 147 (addr=602112)
[00:00:14.820,587] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:14.820,648] <inf> nept_flog: Flog_Format: Erased sector 148 (addr=606208)
[00:00:14.906,738] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:14.906,799] <inf> nept_flog: Flog_Format: Erased sector 149 (addr=610304)
[00:00:14.996,948] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:14.996,978] <inf> nept_flog: Flog_Format: Erased sector 150 (addr=614400)
[00:00:15.086,547] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:15.086,578] <inf> nept_flog: Flog_Format: Erased sector 151 (addr=618496)
[00:00:15.166,870] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:15.166,931] <inf> nept_flog: Flog_Format: Erased sector 152 (addr=622592)
[00:00:15.265,045] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=99ms
[00:00:15.265,106] <inf> nept_flog: Flog_Format: Erased sector 153 (addr=626688)
[00:00:15.351,379] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:15.351,440] <inf> nept_flog: Flog_Format: Erased sector 154 (addr=630784)
[00:00:15.437,469] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:15.437,500] <inf> nept_flog: Flog_Format: Erased sector 155 (addr=634880)
[00:00:15.527,587] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:15.527,648] <inf> nept_flog: Flog_Format: Erased sector 156 (addr=638976)
[00:00:15.613,952] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:15.614,044] <inf> nept_flog: Flog_Format: Erased sector 157 (addr=643072)
[00:00:15.703,247] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:15.703,277] <inf> nept_flog: Flog_Format: Erased sector 158 (addr=647168)
[00:00:15.792,236] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:15.792,266] <inf> nept_flog: Flog_Format: Erased sector 159 (addr=651264)
[00:00:15.875,549] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:15.875,610] <inf> nept_flog: Flog_Format: Erased sector 160 (addr=655360)
[00:00:15.959,991] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:15.960,021] <inf> nept_flog: Flog_Format: Erased sector 161 (addr=659456)
[00:00:16.048,187] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=88ms
[00:00:16.048,278] <inf> nept_flog: Flog_Format: Erased sector 162 (addr=663552)
[00:00:16.134,033] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:16.134,063] <inf> nept_flog: Flog_Format: Erased sector 163 (addr=667648)
[00:00:16.214,294] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:16.214,324] <inf> nept_flog: Flog_Format: Erased sector 164 (addr=671744)
[00:00:16.300,476] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:16.300,537] <inf> nept_flog: Flog_Format: Erased sector 165 (addr=675840)
[00:00:16.390,625] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:16.390,655] <inf> nept_flog: Flog_Format: Erased sector 166 (addr=679936)
[00:00:16.476,226] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:16.476,287] <inf> nept_flog: Flog_Format: Erased sector 167 (addr=684032)
[00:00:16.564,605] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=88ms
[00:00:16.564,636] <inf> nept_flog: Flog_Format: Erased sector 168 (addr=688128)
[00:00:16.650,634] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:16.650,695] <inf> nept_flog: Flog_Format: Erased sector 169 (addr=692224)
[00:00:16.733,459] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:16.733,520] <inf> nept_flog: Flog_Format: Erased sector 170 (addr=696320)
[00:00:16.819,488] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:16.819,519] <inf> nept_flog: Flog_Format: Erased sector 171 (addr=700416)
[00:00:16.900,115] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:16.900,207] <inf> nept_flog: Flog_Format: Erased sector 172 (addr=704512)
[00:00:16.986,145] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:16.986,206] <inf> nept_flog: Flog_Format: Erased sector 173 (addr=708608)
[00:00:17.075,958] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:17.076,019] <inf> nept_flog: Flog_Format: Erased sector 174 (addr=712704)
[00:00:17.161,376] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:17.161,437] <inf> nept_flog: Flog_Format: Erased sector 175 (addr=716800)
[00:00:17.240,875] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=79ms
[00:00:17.240,936] <inf> nept_flog: Flog_Format: Erased sector 176 (addr=720896)
[00:00:17.332,244] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=92ms
[00:00:17.332,305] <inf> nept_flog: Flog_Format: Erased sector 177 (addr=724992)
[00:00:17.411,865] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=79ms
[00:00:17.411,895] <inf> nept_flog: Flog_Format: Erased sector 178 (addr=729088)
[00:00:17.501,068] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:17.501,129] <inf> nept_flog: Flog_Format: Erased sector 179 (addr=733184)
[00:00:17.585,205] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:17.585,266] <inf> nept_flog: Flog_Format: Erased sector 180 (addr=737280)
[00:00:17.671,630] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:17.671,661] <inf> nept_flog: Flog_Format: Erased sector 181 (addr=741376)
[00:00:17.755,859] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:17.755,920] <inf> nept_flog: Flog_Format: Erased sector 182 (addr=745472)
[00:00:17.845,733] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:17.845,764] <inf> nept_flog: Flog_Format: Erased sector 183 (addr=749568)
[00:00:17.926,055] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:17.926,116] <inf> nept_flog: Flog_Format: Erased sector 184 (addr=753664)
[00:00:18.012,207] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:18.012,268] <inf> nept_flog: Flog_Format: Erased sector 185 (addr=757760)
[00:00:18.096,649] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:18.096,710] <inf> nept_flog: Flog_Format: Erased sector 186 (addr=761856)
[00:00:18.183,074] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=87ms
[00:00:18.183,135] <inf> nept_flog: Flog_Format: Erased sector 187 (addr=765952)
[00:00:18.263,824] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:18.263,854] <inf> nept_flog: Flog_Format: Erased sector 188 (addr=770048)
[00:00:18.349,822] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:18.349,884] <inf> nept_flog: Flog_Format: Erased sector 189 (addr=774144)
[00:00:18.430,786] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:18.430,847] <inf> nept_flog: Flog_Format: Erased sector 190 (addr=778240)
[00:00:18.515,869] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:18.515,930] <inf> nept_flog: Flog_Format: Erased sector 191 (addr=782336)
[00:00:18.595,520] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:18.595,581] <inf> nept_flog: Flog_Format: Erased sector 192 (addr=786432)
[00:00:18.686,859] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=91ms
[00:00:18.686,920] <inf> nept_flog: Flog_Format: Erased sector 193 (addr=790528)
[00:00:18.770,416] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:18.770,477] <inf> nept_flog: Flog_Format: Erased sector 194 (addr=794624)
[00:00:18.856,323] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:18.856,384] <inf> nept_flog: Flog_Format: Erased sector 195 (addr=798720)
[00:00:18.936,645] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:18.936,706] <inf> nept_flog: Flog_Format: Erased sector 196 (addr=802816)
[00:00:19.027,252] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=91ms
[00:00:19.027,313] <inf> nept_flog: Flog_Format: Erased sector 197 (addr=806912)
[00:00:19.107,696] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:19.107,757] <inf> nept_flog: Flog_Format: Erased sector 198 (addr=811008)
[00:00:19.193,481] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:19.193,511] <inf> nept_flog: Flog_Format: Erased sector 199 (addr=815104)
[00:00:19.274,108] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:19.274,139] <inf> nept_flog: Flog_Format: Erased sector 200 (addr=819200)
[00:00:19.360,809] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:19.360,839] <inf> nept_flog: Flog_Format: Erased sector 201 (addr=823296)
[00:00:19.441,406] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:19.441,467] <inf> nept_flog: Flog_Format: Erased sector 202 (addr=827392)
[00:00:19.531,616] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=90ms
[00:00:19.531,677] <inf> nept_flog: Flog_Format: Erased sector 203 (addr=831488)
[00:00:19.611,999] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:19.612,060] <inf> nept_flog: Flog_Format: Erased sector 204 (addr=835584)
[00:00:19.698,028] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:19.698,059] <inf> nept_flog: Flog_Format: Erased sector 205 (addr=839680)
[00:00:19.782,135] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:19.782,165] <inf> nept_flog: Flog_Format: Erased sector 206 (addr=843776)
[00:00:19.870,635] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=88ms
[00:00:19.870,697] <inf> nept_flog: Flog_Format: Erased sector 207 (addr=847872)
[00:00:19.953,491] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:19.953,552] <inf> nept_flog: Flog_Format: Erased sector 208 (addr=851968)
[00:00:20.032,806] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=79ms
[00:00:20.032,836] <inf> nept_flog: Flog_Format: Erased sector 209 (addr=856064)
[00:00:20.116,149] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:20.116,180] <inf> nept_flog: Flog_Format: Erased sector 210 (addr=860160)
[00:00:20.201,812] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:20.201,843] <inf> nept_flog: Flog_Format: Erased sector 211 (addr=864256)
[00:00:20.290,588] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:20.290,649] <inf> nept_flog: Flog_Format: Erased sector 212 (addr=868352)
[00:00:20.375,122] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:20.375,183] <inf> nept_flog: Flog_Format: Erased sector 213 (addr=872448)
[00:00:20.455,352] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:20.455,413] <inf> nept_flog: Flog_Format: Erased sector 214 (addr=876544)
[00:00:20.541,320] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:20.541,381] <inf> nept_flog: Flog_Format: Erased sector 215 (addr=880640)
[00:00:20.621,459] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:20.621,490] <inf> nept_flog: Flog_Format: Erased sector 216 (addr=884736)
[00:00:20.705,566] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:20.705,627] <inf> nept_flog: Flog_Format: Erased sector 217 (addr=888832)
[00:00:20.790,435] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:20.790,466] <inf> nept_flog: Flog_Format: Erased sector 218 (addr=892928)
[00:00:20.876,739] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:20.876,800] <inf> nept_flog: Flog_Format: Erased sector 219 (addr=897024)
[00:00:20.957,397] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:20.957,458] <inf> nept_flog: Flog_Format: Erased sector 220 (addr=901120)
[00:00:21.038,970] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:21.039,031] <inf> nept_flog: Flog_Format: Erased sector 221 (addr=905216)
[00:00:21.119,384] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:21.119,445] <inf> nept_flog: Flog_Format: Erased sector 222 (addr=909312)
[00:00:21.204,376] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:21.204,406] <inf> nept_flog: Flog_Format: Erased sector 223 (addr=913408)
[00:00:21.283,508] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=79ms
[00:00:21.283,538] <inf> nept_flog: Flog_Format: Erased sector 224 (addr=917504)
[00:00:21.362,945] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=79ms
[00:00:21.363,006] <inf> nept_flog: Flog_Format: Erased sector 225 (addr=921600)
[00:00:21.442,474] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=79ms
[00:00:21.442,504] <inf> nept_flog: Flog_Format: Erased sector 226 (addr=925696)
[00:00:21.527,374] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:21.527,435] <inf> nept_flog: Flog_Format: Erased sector 227 (addr=929792)
[00:00:21.611,907] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:21.611,968] <inf> nept_flog: Flog_Format: Erased sector 228 (addr=933888)
[00:00:21.692,352] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:21.692,382] <inf> nept_flog: Flog_Format: Erased sector 229 (addr=937984)
[00:00:21.772,735] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:21.772,766] <inf> nept_flog: Flog_Format: Erased sector 230 (addr=942080)
[00:00:21.858,520] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=86ms
[00:00:21.858,581] <inf> nept_flog: Flog_Format: Erased sector 231 (addr=946176)
[00:00:21.938,842] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:21.938,903] <inf> nept_flog: Flog_Format: Erased sector 232 (addr=950272)
[00:00:22.019,287] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:22.019,348] <inf> nept_flog: Flog_Format: Erased sector 233 (addr=954368)
[00:00:22.099,731] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:22.099,792] <inf> nept_flog: Flog_Format: Erased sector 234 (addr=958464)
[00:00:22.193,725] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=94ms
[00:00:22.193,756] <inf> nept_flog: Flog_Format: Erased sector 235 (addr=962560)
[00:00:22.282,470] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=89ms
[00:00:22.282,501] <inf> nept_flog: Flog_Format: Erased sector 236 (addr=966656)
[00:00:22.370,483] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=88ms
[00:00:22.370,544] <inf> nept_flog: Flog_Format: Erased sector 237 (addr=970752)
[00:00:22.454,559] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:22.454,620] <inf> nept_flog: Flog_Format: Erased sector 238 (addr=974848)
[00:00:22.542,785] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=88ms
[00:00:22.542,816] <inf> nept_flog: Flog_Format: Erased sector 239 (addr=978944)
[00:00:22.625,244] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:22.625,305] <inf> nept_flog: Flog_Format: Erased sector 240 (addr=983040)
[00:00:22.704,559] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=79ms
[00:00:22.704,620] <inf> nept_flog: Flog_Format: Erased sector 241 (addr=987136)
[00:00:22.788,177] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:22.788,238] <inf> nept_flog: Flog_Format: Erased sector 242 (addr=991232)
[00:00:22.872,253] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:22.872,283] <inf> nept_flog: Flog_Format: Erased sector 243 (addr=995328)
[00:00:22.952,728] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:22.952,758] <inf> nept_flog: Flog_Format: Erased sector 244 (addr=999424)
[00:00:23.037,109] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=85ms
[00:00:23.037,139] <inf> nept_flog: Flog_Format: Erased sector 245 (addr=1003520)
[00:00:23.121,246] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:23.121,307] <inf> nept_flog: Flog_Format: Erased sector 246 (addr=1007616)
[00:00:23.204,559] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=83ms
[00:00:23.204,620] <inf> nept_flog: Flog_Format: Erased sector 247 (addr=1011712)
[00:00:23.284,790] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:23.284,851] <inf> nept_flog: Flog_Format: Erased sector 248 (addr=1015808)
[00:00:23.365,234] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:23.365,295] <inf> nept_flog: Flog_Format: Erased sector 249 (addr=1019904)
[00:00:23.449,951] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:23.449,981] <inf> nept_flog: Flog_Format: Erased sector 250 (addr=1024000)
[00:00:23.534,210] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:23.534,240] <inf> nept_flog: Flog_Format: Erased sector 251 (addr=1028096)
[00:00:23.618,804] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=84ms
[00:00:23.618,865] <inf> nept_flog: Flog_Format: Erased sector 252 (addr=1032192)
[00:00:23.698,883] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=80ms
[00:00:23.698,913] <inf> nept_flog: Flog_Format: Erased sector 253 (addr=1036288)
[00:00:23.779,205] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=81ms
[00:00:23.779,235] <inf> nept_flog: Flog_Format: Erased sector 254 (addr=1040384)
[00:00:34.865,570] <err> nept_flog: Failed to write to flash err=-5

Checking the datasheet of my flash datasheet, a sector erase can take up to  240ms.

so if i modify the qspi_erase function to include a 250ms sleep per erase like so:

/* QSPI erase */
static int qspi_erase(const struct device *dev, uint32_t addr, uint32_t size)
{
	const struct qspi_nor_config *params = dev->config;
	int rc, rc2;
	int64_t time_stamp = 0; //customised
	int64_t erase_duration = 0; //customised
	int64_t post_erase_wait_duration = 0; //customised

	rc = qspi_nor_write_protection_set(dev, false);
	if (rc != 0) {
		return rc;
	}
	while (size > 0) {
		nrfx_err_t res = !NRFX_SUCCESS;
		uint32_t adj = 0;

		if (size == params->size) {
			/* chip erase */
			res = nrfx_qspi_chip_erase();
			adj = size;
		} else if ((size >= QSPI_BLOCK_SIZE) &&
			   QSPI_IS_BLOCK_ALIGNED(addr)) {
			/* 64 kB block erase */
			res = nrfx_qspi_erase(NRF_QSPI_ERASE_LEN_64KB, addr);
			adj = QSPI_BLOCK_SIZE;
		} else if ((size >= QSPI_SECTOR_SIZE) &&
			   QSPI_IS_SECTOR_ALIGNED(addr)) {
			/* 4kB sector erase */
			time_stamp = k_uptime_get(); //customised
			res = nrfx_qspi_erase(NRF_QSPI_ERASE_LEN_4KB, addr);
			erase_duration = k_uptime_delta(&time_stamp); //customised
			adj = QSPI_SECTOR_SIZE;
		} else {
			/* minimal erase size is at least a sector size */
			LOG_ERR("unsupported at 0x%lx size %zu", (long)addr, size);
			res = NRFX_ERROR_INVALID_PARAM;
		}

		k_sleep(K_MSEC(250)); //customised
		qspi_wait_for_completion(dev, res);
		post_erase_wait_duration = k_uptime_delta(&time_stamp); //customised
		if (res == NRFX_SUCCESS) {
			addr += adj;
			size -= adj;
		} else {
			LOG_ERR("erase error at 0x%lx size %zu", (long)addr, size);
			rc = qspi_get_zephyr_ret_code(res);
			break; 
		}
	}

	LOG_INF("Erase duration=%llims, Post erase Wait Duration=%llims",erase_duration,post_erase_wait_duration);  //customised

	rc2 = qspi_nor_write_protection_set(dev, true);

	return rc != 0 ? rc : rc2;
}

my log looks like this:

[00:00:03.721,435] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:03.721,588] <inf> nept_flog: Flog_Format: Erased sector 0 (addr=0)
[00:00:03.971,832] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:03.971,984] <inf> nept_flog: Flog_Format: Erased sector 1 (addr=4096)
[00:00:04.222,229] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:04.222,412] <inf> nept_flog: Flog_Format: Erased sector 2 (addr=8192)
[00:00:04.472,656] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:04.472,808] <inf> nept_flog: Flog_Format: Erased sector 3 (addr=12288)
[00:00:04.723,052] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:04.723,205] <inf> nept_flog: Flog_Format: Erased sector 4 (addr=16384)
[00:00:04.973,449] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:04.973,602] <inf> nept_flog: Flog_Format: Erased sector 5 (addr=20480)
[00:00:05.223,876] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:05.223,999] <inf> nept_flog: Flog_Format: Erased sector 6 (addr=24576)
[00:00:05.474,243] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:05.474,426] <inf> nept_flog: Flog_Format: Erased sector 7 (addr=28672)
[00:00:05.724,670] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:05.724,822] <inf> nept_flog: Flog_Format: Erased sector 8 (addr=32768)
[00:00:05.975,067] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:05.975,219] <inf> nept_flog: Flog_Format: Erased sector 9 (addr=36864)
[00:00:06.225,463] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:06.225,616] <inf> nept_flog: Flog_Format: Erased sector 10 (addr=40960)
[00:00:06.475,891] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:06.476,013] <inf> nept_flog: Flog_Format: Erased sector 11 (addr=45056)
[00:00:06.726,257] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:06.726,440] <inf> nept_flog: Flog_Format: Erased sector 12 (addr=49152)
[00:00:06.976,654] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:06.976,806] <inf> nept_flog: Flog_Format: Erased sector 13 (addr=53248)
[00:00:07.227,050] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:07.227,203] <inf> nept_flog: Flog_Format: Erased sector 14 (addr=57344)
[00:00:07.477,447] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:07.477,600] <inf> nept_flog: Flog_Format: Erased sector 15 (addr=61440)
[00:00:07.727,874] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:07.727,996] <inf> nept_flog: Flog_Format: Erased sector 16 (addr=65536)
[00:00:07.978,240] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:07.978,424] <inf> nept_flog: Flog_Format: Erased sector 17 (addr=69632)
[00:00:08.228,668] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:08.228,820] <inf> nept_flog: Flog_Format: Erased sector 18 (addr=73728)
[00:00:08.479,064] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:08.479,217] <inf> nept_flog: Flog_Format: Erased sector 19 (addr=77824)
[00:00:08.729,461] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:08.729,614] <inf> nept_flog: Flog_Format: Erased sector 20 (addr=81920)
[00:00:08.979,888] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:08.980,010] <inf> nept_flog: Flog_Format: Erased sector 21 (addr=86016)
[00:00:09.230,255] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:09.230,438] <inf> nept_flog: Flog_Format: Erased sector 22 (addr=90112)
[00:00:09.480,682] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:09.480,834] <inf> nept_flog: Flog_Format: Erased sector 23 (addr=94208)
[00:00:09.731,079] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:09.731,231] <inf> nept_flog: Flog_Format: Erased sector 24 (addr=98304)
[00:00:09.981,475] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:09.981,628] <inf> nept_flog: Flog_Format: Erased sector 25 (addr=102400)
[00:00:10.231,903] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:10.232,025] <inf> nept_flog: Flog_Format: Erased sector 26 (addr=106496)
[00:00:10.482,269] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:10.482,452] <inf> nept_flog: Flog_Format: Erased sector 27 (addr=110592)
[00:00:10.732,696] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:10.732,849] <inf> nept_flog: Flog_Format: Erased sector 28 (addr=114688)
[00:00:10.983,093] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:10.983,245] <inf> nept_flog: Flog_Format: Erased sector 29 (addr=118784)
[00:00:11.233,489] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:11.233,642] <inf> nept_flog: Flog_Format: Erased sector 30 (addr=122880)
[00:00:11.483,917] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:11.484,039] <inf> nept_flog: Flog_Format: Erased sector 31 (addr=126976)
[00:00:11.734,283] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:11.734,466] <inf> nept_flog: Flog_Format: Erased sector 32 (addr=131072)
[00:00:11.984,680] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:11.984,832] <inf> nept_flog: Flog_Format: Erased sector 33 (addr=135168)
[00:00:12.235,076] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:12.235,229] <inf> nept_flog: Flog_Format: Erased sector 34 (addr=139264)
[00:00:12.485,473] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:12.485,626] <inf> nept_flog: Flog_Format: Erased sector 35 (addr=143360)
[00:00:12.735,900] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:12.736,022] <inf> nept_flog: Flog_Format: Erased sector 36 (addr=147456)
[00:00:12.986,267] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:12.986,450] <inf> nept_flog: Flog_Format: Erased sector 37 (addr=151552)
[00:00:13.236,663] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:13.236,816] <inf> nept_flog: Flog_Format: Erased sector 38 (addr=155648)
[00:00:13.487,060] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:13.487,213] <inf> nept_flog: Flog_Format: Erased sector 39 (addr=159744)
[00:00:13.737,457] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:13.737,609] <inf> nept_flog: Flog_Format: Erased sector 40 (addr=163840)
[00:00:13.987,884] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:13.988,006] <inf> nept_flog: Flog_Format: Erased sector 41 (addr=167936)
[00:00:14.238,250] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:14.238,433] <inf> nept_flog: Flog_Format: Erased sector 42 (addr=172032)
[00:00:14.488,677] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:14.488,830] <inf> nept_flog: Flog_Format: Erased sector 43 (addr=176128)
[00:00:14.739,074] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:14.739,227] <inf> nept_flog: Flog_Format: Erased sector 44 (addr=180224)
[00:00:14.989,471] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:14.989,624] <inf> nept_flog: Flog_Format: Erased sector 45 (addr=184320)
[00:00:15.239,898] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:15.240,020] <inf> nept_flog: Flog_Format: Erased sector 46 (addr=188416)
[00:00:15.490,264] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:15.490,447] <inf> nept_flog: Flog_Format: Erased sector 47 (addr=192512)
[00:00:15.740,692] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:15.740,844] <inf> nept_flog: Flog_Format: Erased sector 48 (addr=196608)
[00:00:15.991,119] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:15.991,241] <inf> nept_flog: Flog_Format: Erased sector 49 (addr=200704)
[00:00:16.241,485] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:16.241,638] <inf> nept_flog: Flog_Format: Erased sector 50 (addr=204800)
[00:00:16.491,912] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:16.492,034] <inf> nept_flog: Flog_Format: Erased sector 51 (addr=208896)
[00:00:16.742,279] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:16.742,462] <inf> nept_flog: Flog_Format: Erased sector 52 (addr=212992)
[00:00:16.992,675] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:16.992,828] <inf> nept_flog: Flog_Format: Erased sector 53 (addr=217088)
[00:00:17.243,072] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:17.243,225] <inf> nept_flog: Flog_Format: Erased sector 54 (addr=221184)
[00:00:17.493,469] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:17.493,621] <inf> nept_flog: Flog_Format: Erased sector 55 (addr=225280)
[00:00:17.743,896] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:17.744,018] <inf> nept_flog: Flog_Format: Erased sector 56 (addr=229376)
[00:00:17.994,262] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:17.994,445] <inf> nept_flog: Flog_Format: Erased sector 57 (addr=233472)
[00:00:18.244,689] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:18.244,842] <inf> nept_flog: Flog_Format: Erased sector 58 (addr=237568)
[00:00:18.495,086] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:18.495,239] <inf> nept_flog: Flog_Format: Erased sector 59 (addr=241664)
[00:00:18.745,483] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:18.745,635] <inf> nept_flog: Flog_Format: Erased sector 60 (addr=245760)
[00:00:18.995,910] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:18.996,032] <inf> nept_flog: Flog_Format: Erased sector 61 (addr=249856)
[00:00:19.246,276] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:19.246,459] <inf> nept_flog: Flog_Format: Erased sector 62 (addr=253952)
[00:00:19.496,673] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:19.496,826] <inf> nept_flog: Flog_Format: Erased sector 63 (addr=258048)
[00:00:19.747,070] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:19.747,222] <inf> nept_flog: Flog_Format: Erased sector 64 (addr=262144)
[00:00:19.997,467] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:19.997,619] <inf> nept_flog: Flog_Format: Erased sector 65 (addr=266240)
[00:00:20.247,894] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:20.248,016] <inf> nept_flog: Flog_Format: Erased sector 66 (addr=270336)
[00:00:20.498,260] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:20.498,443] <inf> nept_flog: Flog_Format: Erased sector 67 (addr=274432)
[00:00:20.748,687] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:20.748,840] <inf> nept_flog: Flog_Format: Erased sector 68 (addr=278528)
[00:00:20.999,084] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:20.999,237] <inf> nept_flog: Flog_Format: Erased sector 69 (addr=282624)
[00:00:21.249,481] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:21.249,633] <inf> nept_flog: Flog_Format: Erased sector 70 (addr=286720)
[00:00:21.499,908] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:21.500,030] <inf> nept_flog: Flog_Format: Erased sector 71 (addr=290816)
[00:00:21.750,274] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:21.750,457] <inf> nept_flog: Flog_Format: Erased sector 72 (addr=294912)
[00:00:22.000,671] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:22.000,823] <inf> nept_flog: Flog_Format: Erased sector 73 (addr=299008)
[00:00:22.251,068] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:22.251,220] <inf> nept_flog: Flog_Format: Erased sector 74 (addr=303104)
[00:00:22.501,464] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:22.501,617] <inf> nept_flog: Flog_Format: Erased sector 75 (addr=307200)
[00:00:22.751,892] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:22.752,014] <inf> nept_flog: Flog_Format: Erased sector 76 (addr=311296)
[00:00:23.002,288] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:23.002,441] <inf> nept_flog: Flog_Format: Erased sector 77 (addr=315392)
[00:00:23.252,685] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:23.252,838] <inf> nept_flog: Flog_Format: Erased sector 78 (addr=319488)
[00:00:23.503,082] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:23.503,234] <inf> nept_flog: Flog_Format: Erased sector 79 (addr=323584)
[00:00:23.753,479] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:23.753,631] <inf> nept_flog: Flog_Format: Erased sector 80 (addr=327680)
[00:00:24.003,906] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:24.004,028] <inf> nept_flog: Flog_Format: Erased sector 81 (addr=331776)
[00:00:24.254,272] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:24.254,455] <inf> nept_flog: Flog_Format: Erased sector 82 (addr=335872)
[00:00:24.504,669] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:24.504,821] <inf> nept_flog: Flog_Format: Erased sector 83 (addr=339968)
[00:00:24.755,065] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:24.755,218] <inf> nept_flog: Flog_Format: Erased sector 84 (addr=344064)
[00:00:25.005,462] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:25.005,615] <inf> nept_flog: Flog_Format: Erased sector 85 (addr=348160)
[00:00:25.255,889] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:25.256,011] <inf> nept_flog: Flog_Format: Erased sector 86 (addr=352256)
[00:00:25.506,256] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:25.506,439] <inf> nept_flog: Flog_Format: Erased sector 87 (addr=356352)
[00:00:25.756,652] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:25.756,805] <inf> nept_flog: Flog_Format: Erased sector 88 (addr=360448)
[00:00:26.007,049] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:26.007,202] <inf> nept_flog: Flog_Format: Erased sector 89 (addr=364544)
[00:00:26.257,446] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:26.257,598] <inf> nept_flog: Flog_Format: Erased sector 90 (addr=368640)
[00:00:26.507,873] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:26.507,995] <inf> nept_flog: Flog_Format: Erased sector 91 (addr=372736)
[00:00:26.758,239] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:26.758,422] <inf> nept_flog: Flog_Format: Erased sector 92 (addr=376832)
[00:00:27.008,636] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:27.008,789] <inf> nept_flog: Flog_Format: Erased sector 93 (addr=380928)
[00:00:27.259,033] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:27.259,185] <inf> nept_flog: Flog_Format: Erased sector 94 (addr=385024)
[00:00:27.509,429] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:27.509,582] <inf> nept_flog: Flog_Format: Erased sector 95 (addr=389120)
[00:00:27.759,857] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:27.759,979] <inf> nept_flog: Flog_Format: Erased sector 96 (addr=393216)
[00:00:28.010,223] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:28.010,406] <inf> nept_flog: Flog_Format: Erased sector 97 (addr=397312)
[00:00:28.260,620] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:28.260,772] <inf> nept_flog: Flog_Format: Erased sector 98 (addr=401408)
[00:00:28.511,016] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:28.511,169] <inf> nept_flog: Flog_Format: Erased sector 99 (addr=405504)
[00:00:28.761,413] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:28.761,566] <inf> nept_flog: Flog_Format: Erased sector 100 (addr=409600)
[00:00:29.011,840] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:29.011,962] <inf> nept_flog: Flog_Format: Erased sector 101 (addr=413696)
[00:00:29.262,207] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:29.262,390] <inf> nept_flog: Flog_Format: Erased sector 102 (addr=417792)
[00:00:29.512,603] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:29.512,756] <inf> nept_flog: Flog_Format: Erased sector 103 (addr=421888)
[00:00:29.763,000] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:29.763,153] <inf> nept_flog: Flog_Format: Erased sector 104 (addr=425984)
[00:00:30.013,427] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:30.013,549] <inf> nept_flog: Flog_Format: Erased sector 105 (addr=430080)
[00:00:30.263,824] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:30.263,946] <inf> nept_flog: Flog_Format: Erased sector 106 (addr=434176)
[00:00:30.514,190] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:30.514,373] <inf> nept_flog: Flog_Format: Erased sector 107 (addr=438272)
[00:00:30.764,587] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:30.764,739] <inf> nept_flog: Flog_Format: Erased sector 108 (addr=442368)
[00:00:31.014,984] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:31.015,136] <inf> nept_flog: Flog_Format: Erased sector 109 (addr=446464)
[00:00:31.265,380] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:31.265,533] <inf> nept_flog: Flog_Format: Erased sector 110 (addr=450560)
[00:00:31.515,808] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:31.515,930] <inf> nept_flog: Flog_Format: Erased sector 111 (addr=454656)
[00:00:31.766,174] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:31.766,357] <inf> nept_flog: Flog_Format: Erased sector 112 (addr=458752)
[00:00:32.016,571] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:32.016,723] <inf> nept_flog: Flog_Format: Erased sector 113 (addr=462848)
[00:00:32.266,967] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:32.267,120] <inf> nept_flog: Flog_Format: Erased sector 114 (addr=466944)
[00:00:32.517,364] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:32.517,517] <inf> nept_flog: Flog_Format: Erased sector 115 (addr=471040)
[00:00:32.767,761] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:32.767,913] <inf> nept_flog: Flog_Format: Erased sector 116 (addr=475136)
[00:00:33.018,157] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:33.018,341] <inf> nept_flog: Flog_Format: Erased sector 117 (addr=479232)
[00:00:33.268,554] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:33.268,707] <inf> nept_flog: Flog_Format: Erased sector 118 (addr=483328)
[00:00:33.518,951] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:33.519,104] <inf> nept_flog: Flog_Format: Erased sector 119 (addr=487424)
[00:00:33.769,348] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:33.769,500] <inf> nept_flog: Flog_Format: Erased sector 120 (addr=491520)
[00:00:34.019,744] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:34.019,897] <inf> nept_flog: Flog_Format: Erased sector 121 (addr=495616)
[00:00:34.270,141] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:34.270,324] <inf> nept_flog: Flog_Format: Erased sector 122 (addr=499712)
[00:00:34.520,538] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:34.520,690] <inf> nept_flog: Flog_Format: Erased sector 123 (addr=503808)
[00:00:34.770,935] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:34.771,087] <inf> nept_flog: Flog_Format: Erased sector 124 (addr=507904)
[00:00:35.021,331] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:35.021,484] <inf> nept_flog: Flog_Format: Erased sector 125 (addr=512000)
[00:00:35.271,728] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:35.271,881] <inf> nept_flog: Flog_Format: Erased sector 126 (addr=516096)
[00:00:35.522,125] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:35.522,308] <inf> nept_flog: Flog_Format: Erased sector 127 (addr=520192)
[00:00:35.772,521] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:35.772,674] <inf> nept_flog: Flog_Format: Erased sector 128 (addr=524288)
[00:00:36.022,918] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:36.023,071] <inf> nept_flog: Flog_Format: Erased sector 129 (addr=528384)
[00:00:36.273,315] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:36.273,468] <inf> nept_flog: Flog_Format: Erased sector 130 (addr=532480)
[00:00:36.523,712] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:36.523,864] <inf> nept_flog: Flog_Format: Erased sector 131 (addr=536576)
[00:00:36.774,108] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:36.774,261] <inf> nept_flog: Flog_Format: Erased sector 132 (addr=540672)
[00:00:37.024,536] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:37.024,658] <inf> nept_flog: Flog_Format: Erased sector 133 (addr=544768)
[00:00:37.274,902] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:37.275,054] <inf> nept_flog: Flog_Format: Erased sector 134 (addr=548864)
[00:00:37.525,299] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:37.525,451] <inf> nept_flog: Flog_Format: Erased sector 135 (addr=552960)
[00:00:37.775,695] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:37.775,848] <inf> nept_flog: Flog_Format: Erased sector 136 (addr=557056)
[00:00:38.026,092] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:38.026,275] <inf> nept_flog: Flog_Format: Erased sector 137 (addr=561152)
[00:00:38.276,489] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:38.276,641] <inf> nept_flog: Flog_Format: Erased sector 138 (addr=565248)
[00:00:38.526,885] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:38.527,038] <inf> nept_flog: Flog_Format: Erased sector 139 (addr=569344)
[00:00:38.777,282] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:38.777,435] <inf> nept_flog: Flog_Format: Erased sector 140 (addr=573440)
[00:00:39.027,679] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:39.027,832] <inf> nept_flog: Flog_Format: Erased sector 141 (addr=577536)
[00:00:39.278,076] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:39.278,259] <inf> nept_flog: Flog_Format: Erased sector 142 (addr=581632)
[00:00:39.528,472] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:39.528,625] <inf> nept_flog: Flog_Format: Erased sector 143 (addr=585728)
[00:00:39.778,869] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:39.779,022] <inf> nept_flog: Flog_Format: Erased sector 144 (addr=589824)
[00:00:40.029,266] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:40.029,418] <inf> nept_flog: Flog_Format: Erased sector 145 (addr=593920)
[00:00:40.279,663] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:40.279,815] <inf> nept_flog: Flog_Format: Erased sector 146 (addr=598016)
[00:00:40.530,059] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:40.530,242] <inf> nept_flog: Flog_Format: Erased sector 147 (addr=602112)
[00:00:40.780,456] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:40.780,609] <inf> nept_flog: Flog_Format: Erased sector 148 (addr=606208)
[00:00:41.030,853] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:41.031,005] <inf> nept_flog: Flog_Format: Erased sector 149 (addr=610304)
[00:00:41.281,250] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:41.281,402] <inf> nept_flog: Flog_Format: Erased sector 150 (addr=614400)
[00:00:41.531,646] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:41.531,799] <inf> nept_flog: Flog_Format: Erased sector 151 (addr=618496)
[00:00:41.782,043] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:41.782,196] <inf> nept_flog: Flog_Format: Erased sector 152 (addr=622592)
[00:00:42.032,440] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:42.032,592] <inf> nept_flog: Flog_Format: Erased sector 153 (addr=626688)
[00:00:42.282,836] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:42.282,989] <inf> nept_flog: Flog_Format: Erased sector 154 (addr=630784)
[00:00:42.533,233] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:42.533,386] <inf> nept_flog: Flog_Format: Erased sector 155 (addr=634880)
[00:00:42.783,630] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:42.783,782] <inf> nept_flog: Flog_Format: Erased sector 156 (addr=638976)
[00:00:43.034,027] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:43.034,179] <inf> nept_flog: Flog_Format: Erased sector 157 (addr=643072)
[00:00:43.284,423] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:43.284,576] <inf> nept_flog: Flog_Format: Erased sector 158 (addr=647168)
[00:00:43.534,820] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:43.534,973] <inf> nept_flog: Flog_Format: Erased sector 159 (addr=651264)
[00:00:43.785,217] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:43.785,369] <inf> nept_flog: Flog_Format: Erased sector 160 (addr=655360)
[00:00:44.035,644] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:44.035,766] <inf> nept_flog: Flog_Format: Erased sector 161 (addr=659456)
[00:00:44.286,010] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:44.286,163] <inf> nept_flog: Flog_Format: Erased sector 162 (addr=663552)
[00:00:44.536,407] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:44.536,560] <inf> nept_flog: Flog_Format: Erased sector 163 (addr=667648)
[00:00:44.786,804] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:44.786,956] <inf> nept_flog: Flog_Format: Erased sector 164 (addr=671744)
[00:00:45.037,200] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:45.037,353] <inf> nept_flog: Flog_Format: Erased sector 165 (addr=675840)
[00:00:45.287,628] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:45.287,750] <inf> nept_flog: Flog_Format: Erased sector 166 (addr=679936)
[00:00:45.537,994] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:45.538,177] <inf> nept_flog: Flog_Format: Erased sector 167 (addr=684032)
[00:00:45.788,391] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:45.788,543] <inf> nept_flog: Flog_Format: Erased sector 168 (addr=688128)
[00:00:46.038,787] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:46.038,940] <inf> nept_flog: Flog_Format: Erased sector 169 (addr=692224)
[00:00:46.289,184] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:46.289,337] <inf> nept_flog: Flog_Format: Erased sector 170 (addr=696320)
[00:00:46.539,581] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:46.539,733] <inf> nept_flog: Flog_Format: Erased sector 171 (addr=700416)
[00:00:46.789,978] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:46.790,161] <inf> nept_flog: Flog_Format: Erased sector 172 (addr=704512)
[00:00:47.040,374] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:47.040,527] <inf> nept_flog: Flog_Format: Erased sector 173 (addr=708608)
[00:00:47.290,771] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:47.290,924] <inf> nept_flog: Flog_Format: Erased sector 174 (addr=712704)
[00:00:47.541,168] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:47.541,320] <inf> nept_flog: Flog_Format: Erased sector 175 (addr=716800)
[00:00:47.791,564] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:47.791,717] <inf> nept_flog: Flog_Format: Erased sector 176 (addr=720896)
[00:00:48.041,961] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:48.042,144] <inf> nept_flog: Flog_Format: Erased sector 177 (addr=724992)
[00:00:48.292,358] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:48.292,510] <inf> nept_flog: Flog_Format: Erased sector 178 (addr=729088)
[00:00:48.542,755] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:48.542,907] <inf> nept_flog: Flog_Format: Erased sector 179 (addr=733184)
[00:00:48.793,151] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:48.793,304] <inf> nept_flog: Flog_Format: Erased sector 180 (addr=737280)
[00:00:49.043,548] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:49.043,701] <inf> nept_flog: Flog_Format: Erased sector 181 (addr=741376)
[00:00:49.293,945] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:49.294,128] <inf> nept_flog: Flog_Format: Erased sector 182 (addr=745472)
[00:00:49.544,342] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:49.544,494] <inf> nept_flog: Flog_Format: Erased sector 183 (addr=749568)
[00:00:49.794,738] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:49.794,891] <inf> nept_flog: Flog_Format: Erased sector 184 (addr=753664)
[00:00:50.045,135] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:50.045,288] <inf> nept_flog: Flog_Format: Erased sector 185 (addr=757760)
[00:00:50.295,532] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:50.295,684] <inf> nept_flog: Flog_Format: Erased sector 186 (addr=761856)
[00:00:50.545,928] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:50.546,112] <inf> nept_flog: Flog_Format: Erased sector 187 (addr=765952)
[00:00:50.796,325] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:50.796,478] <inf> nept_flog: Flog_Format: Erased sector 188 (addr=770048)
[00:00:51.046,752] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:51.046,875] <inf> nept_flog: Flog_Format: Erased sector 189 (addr=774144)
[00:00:51.297,119] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:51.297,271] <inf> nept_flog: Flog_Format: Erased sector 190 (addr=778240)
[00:00:51.547,515] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:51.547,668] <inf> nept_flog: Flog_Format: Erased sector 191 (addr=782336)
[00:00:51.797,912] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:51.798,065] <inf> nept_flog: Flog_Format: Erased sector 192 (addr=786432)
[00:00:52.048,309] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:52.048,461] <inf> nept_flog: Flog_Format: Erased sector 193 (addr=790528)
[00:00:52.298,706] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:52.298,858] <inf> nept_flog: Flog_Format: Erased sector 194 (addr=794624)
[00:00:52.549,102] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:52.549,255] <inf> nept_flog: Flog_Format: Erased sector 195 (addr=798720)
[00:00:52.799,499] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:52.799,652] <inf> nept_flog: Flog_Format: Erased sector 196 (addr=802816)
[00:00:53.049,896] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:53.050,048] <inf> nept_flog: Flog_Format: Erased sector 197 (addr=806912)
[00:00:53.300,292] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:53.300,445] <inf> nept_flog: Flog_Format: Erased sector 198 (addr=811008)
[00:00:53.550,689] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:53.550,842] <inf> nept_flog: Flog_Format: Erased sector 199 (addr=815104)
[00:00:53.801,086] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:53.801,239] <inf> nept_flog: Flog_Format: Erased sector 200 (addr=819200)
[00:00:54.051,483] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:54.051,635] <inf> nept_flog: Flog_Format: Erased sector 201 (addr=823296)
[00:00:54.301,879] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:54.302,062] <inf> nept_flog: Flog_Format: Erased sector 202 (addr=827392)
[00:00:54.552,276] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:54.552,429] <inf> nept_flog: Flog_Format: Erased sector 203 (addr=831488)
[00:00:54.802,673] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:54.802,825] <inf> nept_flog: Flog_Format: Erased sector 204 (addr=835584)
[00:00:55.053,070] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:55.053,222] <inf> nept_flog: Flog_Format: Erased sector 205 (addr=839680)
[00:00:55.303,497] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:55.303,619] <inf> nept_flog: Flog_Format: Erased sector 206 (addr=843776)
[00:00:55.553,863] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:55.554,046] <inf> nept_flog: Flog_Format: Erased sector 207 (addr=847872)
[00:00:55.804,260] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:55.804,412] <inf> nept_flog: Flog_Format: Erased sector 208 (addr=851968)
[00:00:56.054,656] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:56.054,809] <inf> nept_flog: Flog_Format: Erased sector 209 (addr=856064)
[00:00:56.305,053] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:56.305,206] <inf> nept_flog: Flog_Format: Erased sector 210 (addr=860160)
[00:00:56.555,450] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:56.555,603] <inf> nept_flog: Flog_Format: Erased sector 211 (addr=864256)
[00:00:56.805,847] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:56.806,030] <inf> nept_flog: Flog_Format: Erased sector 212 (addr=868352)
[00:00:57.056,243] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:57.056,396] <inf> nept_flog: Flog_Format: Erased sector 213 (addr=872448)
[00:00:57.306,640] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:57.306,793] <inf> nept_flog: Flog_Format: Erased sector 214 (addr=876544)
[00:00:57.557,037] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:57.557,189] <inf> nept_flog: Flog_Format: Erased sector 215 (addr=880640)
[00:00:57.807,434] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:57.807,586] <inf> nept_flog: Flog_Format: Erased sector 216 (addr=884736)
[00:00:58.057,861] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:58.058,013] <inf> nept_flog: Flog_Format: Erased sector 217 (addr=888832)
[00:00:58.308,227] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:58.308,380] <inf> nept_flog: Flog_Format: Erased sector 218 (addr=892928)
[00:00:58.558,624] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:58.558,776] <inf> nept_flog: Flog_Format: Erased sector 219 (addr=897024)
[00:00:58.809,020] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:00:58.809,173] <inf> nept_flog: Flog_Format: Erased sector 220 (addr=901120)
[00:00:59.059,417] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:59.059,570] <inf> nept_flog: Flog_Format: Erased sector 221 (addr=905216)
[00:00:59.309,814] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:59.309,967] <inf> nept_flog: Flog_Format: Erased sector 222 (addr=909312)
[00:00:59.560,211] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:59.560,363] <inf> nept_flog: Flog_Format: Erased sector 223 (addr=913408)
[00:00:59.810,607] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:00:59.810,760] <inf> nept_flog: Flog_Format: Erased sector 224 (addr=917504)
[00:01:00.061,004] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=251ms
[00:01:00.061,157] <inf> nept_flog: Flog_Format: Erased sector 225 (addr=921600)
[00:01:00.311,401] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:00.311,553] <inf> nept_flog: Flog_Format: Erased sector 226 (addr=925696)
[00:01:00.561,798] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:00.561,950] <inf> nept_flog: Flog_Format: Erased sector 227 (addr=929792)
[00:01:00.812,194] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:00.812,347] <inf> nept_flog: Flog_Format: Erased sector 228 (addr=933888)
[00:01:01.062,591] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:01.062,744] <inf> nept_flog: Flog_Format: Erased sector 229 (addr=937984)
[00:01:01.312,988] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:01.313,140] <inf> nept_flog: Flog_Format: Erased sector 230 (addr=942080)
[00:01:01.348,297] <inf> nept_fuel_gauge: V: 3.793, I: 0.007, T: 17.64, 
[00:01:01.348,327] <inf> nept_fuel_gauge: SoC: 65.79, TTE: nan, TTF: nan
[00:01:01.563,385] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:01.563,537] <inf> nept_flog: Flog_Format: Erased sector 231 (addr=946176)
[00:01:01.813,781] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:01.813,934] <inf> nept_flog: Flog_Format: Erased sector 232 (addr=950272)
[00:01:02.064,178] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:02.064,331] <inf> nept_flog: Flog_Format: Erased sector 233 (addr=954368)
[00:01:02.314,575] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:02.314,727] <inf> nept_flog: Flog_Format: Erased sector 234 (addr=958464)
[00:01:02.564,971] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:02.565,124] <inf> nept_flog: Flog_Format: Erased sector 235 (addr=962560)
[00:01:02.815,368] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:02.815,521] <inf> nept_flog: Flog_Format: Erased sector 236 (addr=966656)
[00:01:03.065,765] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:03.065,917] <inf> nept_flog: Flog_Format: Erased sector 237 (addr=970752)
[00:01:03.316,162] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:03.316,314] <inf> nept_flog: Flog_Format: Erased sector 238 (addr=974848)
[00:01:03.566,558] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:03.566,711] <inf> nept_flog: Flog_Format: Erased sector 239 (addr=978944)
[00:01:03.816,955] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:03.817,108] <inf> nept_flog: Flog_Format: Erased sector 240 (addr=983040)
[00:01:04.067,352] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:04.067,504] <inf> nept_flog: Flog_Format: Erased sector 241 (addr=987136)
[00:01:04.317,749] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:04.317,901] <inf> nept_flog: Flog_Format: Erased sector 242 (addr=991232)
[00:01:04.568,145] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:04.568,298] <inf> nept_flog: Flog_Format: Erased sector 243 (addr=995328)
[00:01:04.818,572] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:04.818,695] <inf> nept_flog: Flog_Format: Erased sector 244 (addr=999424)
[00:01:05.068,939] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:05.069,091] <inf> nept_flog: Flog_Format: Erased sector 245 (addr=1003520)
[00:01:05.319,335] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:05.319,519] <inf> nept_flog: Flog_Format: Erased sector 246 (addr=1007616)
[00:01:05.569,732] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:05.569,885] <inf> nept_flog: Flog_Format: Erased sector 247 (addr=1011712)
[00:01:05.820,129] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:05.820,281] <inf> nept_flog: Flog_Format: Erased sector 248 (addr=1015808)
[00:01:06.070,526] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:06.070,678] <inf> nept_flog: Flog_Format: Erased sector 249 (addr=1019904)
[00:01:06.320,922] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:06.321,075] <inf> nept_flog: Flog_Format: Erased sector 250 (addr=1024000)
[00:01:06.571,319] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:06.571,502] <inf> nept_flog: Flog_Format: Erased sector 251 (addr=1028096)
[00:01:06.821,716] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:06.821,868] <inf> nept_flog: Flog_Format: Erased sector 252 (addr=1032192)
[00:01:07.072,113] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:07.072,265] <inf> nept_flog: Flog_Format: Erased sector 253 (addr=1036288)
[00:01:07.322,509] <inf> qspi_nor: Erase duration=0ms, Post erase Wait Duration=250ms
[00:01:07.322,662] <inf> nept_flog: Flog_Format: Erased sector 254 (addr=1040384)

Note that are no errors for pm_device_runtime_put or the flash write.

I hope this is enough evidence that there is a problem with the library.

It also worth nothing the chip erase cycle time is max 30 seconds and if i chip erase instead it's 250ms x 256 sectors = 64 seconds so i have to wait quite a bit longer if i can't use the chip erase. More importantly neither work right now.

Robert

[Sigurd Hellesvik]

I have created a Jira ticket to get our qspi driver developers to look into this.

[robsrick]

thanks!

[BertL]

It seems that i'm running into the same issue with sdk 2.6.0. I'm writing to a littlefs partition on external flash connected through qspi and sometimes I also get the pm_device_runtime_put failed: -16 error in the logs. When this happens the write seems to fail and the consumption of the device goes from 30 uA to almost 1mA.

I expect that this happens when littlefs has to erase a sector on the flash.

Hope that there is a solution soon, if I can test anything, just let me know!

[BertL]

For now I'm using the suggestion of robsrick to add a 250ms sleep before qspi_wait_for_completion in the qspi_erase function. With this hack, the issue cannot be reproduced anymore.

Of course I'm very interested in a proper fix ;)